A Treatise on Group Policy Troubleshooting–now with GPSVC Log Analysis!

First published on TechNet on Apr 17, 2015

Hi all, David Ani here from Romania. This guide outlines basic steps used to troubleshoot Group Policy application errors using the Group Policy Service Debug logs (gpsvc.log). A basic understanding of the logging discussed here will save time and may prevent you from having to open a support ticket with Microsoft. Let's get started.

The gpsvc log has evolved from the User Environment Debug Logs (userenv log) in Windows XP and Windows Server 2003 but the basics are still there and the pattern is the same. There are also changes from 2008 to 2012 in the logging itself but they are minor and will not prevent you from understanding your first steps in analyzing the debug logs.

Overview of Group Policy Client Service (GPSVC)

• One of the major changes that came with Windows Vista and later operating systems is the new Group Policy Client service. Earlier operating systems used the WinLogon service to apply Group Policy. However, the new Group Policy Client service improves the overall stability of the Group Policy infrastructure and the operating system by isolating it from the WinLogon process.
  
• The service is responsible for applying settings configured by administrators to computers and users through the Group Policy component. If the service is stopped or disabled, the settings will not be applied, so applications and components will not be manageable through Group Policy. Please keep in mind that, to increased security, users cannot start or stop the Group Policy Client service. In the Services snap-in, the options to start, stop, pause, and resume the Group Policy client are unavailable.
  
• Finally, any components or applications that depend on the Group Policy component will not be functional if the service is stopped or disabled.

Note: The important thing to remember is that the Group Policy Client is a service running on every OS since Vista and is responsible for applying GPOs. The process itself will run under a svchost instance, which you can check by using the “tasklist /svc” command line.

One final point: Since the startup value for the service is Automatic ( Trigger Start ), you may not always see it in the list of running services. It will start, perform its actions, and then stop.

Group Policy processing overview
Group Policy processing happens in two phases:

• Group Policy Core Processing - where the client enumerates all Group Policies together with all settings that need to be applied. It will connect to a Domain Controller, accessing Active Directory and SYSVOL and gather all the required data in order to process the policies.
  
• Group Policy CSE Processing - Client Side Extensions (CSEs) are responsible for client side policy processing. These CSEs ensure all settings configured in the GPOs will be applied to the workstation or server.

Note: The Group Policy architecture includes both server and client-side components. The server component includes the user interface (GPEdit.msc, GPMC.msc) that an administrator can use to configure a unique policy. GPEdit.msc is always present even on client SKU's while GPMC.msc and GPME.msc get installed either via RSAT or if the machine is a domain controller. When Group Policy is applied to a user or computer, the client component interprets the policy and makes the appropriate changes to the environment. These are known as Group Policy client-side extensions.

See the following post for a reference list for most of the CSEs: http://blogs.technet.com/b/mempson/archive/2010/12/01/group-policy-client-side-extension-list.aspx

In troubleshooting a given extension's application of policy, the administrator can view the configuration parameters for that extension. These parameters are in the form of registry values. There are two things to keep in mind:

• When configuring GPOs in your Domain you must make sure they have been replicated to all domain controllers, both in AD and SYSVOL. It is important to understand that AD replication is not the same as SYSVOL replication and one can be successful while the other may not. However, if you have a Windows 8 or Windows Server 2012 or later OS, this is easily verified using the Group Policy Management Console (GPMC) and the status tab for an Organizational Unit (OU).
  
• At a high level, we know that the majority of your GPO settings are just registry keys that need to be delivered and set on a client under the user or machine keys.

First troubleshooting steps

• Start by using GPResult or the Group Policy Results wizard in GPMC and check which GPOs have been applied. What are the winning GPOs? Are there contradictory settings? Finally, be on the lookout for Loopback Policy Processing that can sometimes deliver unexpected results.

Note: To have a better understanding of Loopback Policy Processing please review this post: http:// blogs.technet.com/b/askds/archive/2013/02/08/circle-back-to-loopback.aspx

• On the target client, you can run GPResult /v or /h and verify that the GPO is there and listed under “Applied GPOs.” Is it listed? It should look the same as the results from the Group Policy Results wizard in GPMC. If not verify replication and that policy has been recently applied.

Note: You can always force a group policy update on a client with gpupdate /force. This will require admin privileges for the computer side policies. If you do not have admin rights an old fashioned reboot should force policy to apply.

• If the Group Policy is unexpectedly listed under “Denied GPOs”, then please check the following:

– If the reason for “Denied GPOs” is empty, then you probably have linked a User Configuration GPO to an OU with computers or the other way around. Link the GPO to the corresponding OU, the one which contains your users.

– If the reason for “Denied GPOs” is “Access Denied (Security Filtering)”, then make sure you have the correct objects (Authenticated Users or desired Group) in “Security Filtering” in GPMC. Target objects need at least “Read” and “Apply Group Policy” permissions.

– If the reason for “Denied GPOs” is “False WMI Filter”, then make sure you configure the WMI filter accordingly, so that the GPO works with the WMI filter for the desired user and computers.

See the following TechNet reference for more on WMI Filters: http://technet.microsoft.com/en-us/library/cc787382(v=ws.10). aspx

– If the Group Policy isn’t listed in gpresult.exe at all, verify the scope by ensuring that either the user or computer object in Active Directory reside in the OU tree the Group Policy is linked to in GPMC.

Start Advanced Troubleshooting

• If the problem cannot be identified from the previous steps, then we can enable gpsvc logging. On the client where the GPO Problem occurs follow these steps to enable Group Policy Service debug logging.

1. Click Start , click Run , type regedit, and then click OK .
2. Locate and then click the following registry subkey: HKEY_LOCAL_MACHINE\Software\Microsoft\Windows NT\CurrentVersion
3. On the Edit menu, point to New , and then click Key .
4. Type Diagnostics, and then press ENTER .
5. Right-click the Diagnostics subkey, point to New , and then click DWORD (32-bit) Value .
6. Type GPSvcDebugLevel, and then press ENTER .
7. Right-click GPSvcDebugLevel, and then click Modify .
8. In the Value data box, type 30002 (Hexadecimal), and then click OK .

9. Exit Registry Editor.
10. View the Gpsvc.log file in the following folder: %windir%\debug\usermode

Note - If the usermode folder does not exist, create it under %windir%\debug.
If the usermode folder does not exist under %WINDIR%\debug\ the gpsvc.log file will not be created.

• Now, you can either do a “gpupdate /force” to trigger GPO processing or do a restart of the machine in order to get a clean boot application of group policy (Foreground vs Background GPO Processing).
• After that, the log itself should be found under: C:\Windows\Debug\Usermode\gpsvc.log

An important note for Windows 7/ Windows Server 2008 R2 or older operating systems to consider: On multiprocessor machines, we might have concurrent threads writing to log at the same time. In heavy logging scenarios, one of the writes attempts may fail and we may possibly lose debug log information.
Concurrent processing is very common with group policy troubleshooting since you usually run "gpupdate /force" without specifying user or machine processing separately. To reduce the chance of lost logging while troubleshooting, initiate machine and user policy processing separately:

• Gpupdate /force /target:computer
• Gpupdate /force /target:user

Analysis - Understanding PID, TID and Dependencies
Now let's get started with the GPSVC Log analysis! The first thing to understand is the Process Identifier (PID) and Thread Identifier (TID) of a gpsvc log. Here is an example:

GPSVC( 31c.328 ) 10:01:56:711 GroupPolicyClientServiceMain

What are those? As an example I took “GPSVC( 31c.328 )”, where the first number is 31c, which directly relates to the PID. The second number is 328, which relates to the TID. We know that the 31c doesn’t look like a PID, but that’s because it is in Hexadecimal. By translating it into decimal, you will get the PID of the process for the SVCHOST containing the GPSVC.

Then we have a TID, which will differ for every thread the GPClient is working on. One thing to consider: we will have two different threads for Machine and User GPO processing, so make sure you follow the correct one.

Example:

GPSVC(31c.328) 10:01:56:711 CGPService::Start: InstantiateGPEngine
GPSVC(31c.328) 10:01:56:726 CGPService::InitializeRPCServer starting RPCServer
GPSVC(31c.328) 10:01:56:741 CGPService::InitializeRPCServer finished starting RPCServer. status 0x0
GPSVC(31c.328) 10:01:56:741 CGPService::Start: CreateGPSessions
GPSVC(31c.328) 10:01:56:758 Updating the service status to be RUNNING.

This shows that the GPService Engine is being started and we can see that it also checks for dependencies (RPCServer) to be started.

Synchronous vs Asynchronous Processing
I will not spend a lot of time explaining this because there is a great post from the GP Team out there which explains this very well. This is important to understand because it has a big impact on how settings are applied and when. Look at:
http :// blogs.technet.com/b/grouppolicy/archive/2013/05/23/group-policy-and-logon-impact.aspx

Synchronous vs. asynchronous processing
Foreground processing can operate under two different modes—synchronously or asynchronously. The default foreground processing mode for Windows clients since Windows XP has been asynchronous.

Asynchronous GP processing does not prevent the user from using their desktop while GP processing completes. For example, when the computer is starting up GP asynchronous processing starts to occur for the computer. In the meantime, the user is presented the Windows logon prompt. Likewise, for asynchronous user processing, the user logs on and is presented with their desktop while GP finishes processing. There is no delay in getting either their logon prompt or their desktop during asynchronous GP processing. When foreground processing is synchronous, the user is not presented with the logon prompt until computer GP processing has completed after a system boot. Likewise the user will not see their desktop at logon until user GP processing completes. This can have the effect of making the user feel like the system is running slow. To summarize, synchronous processing can impact startup time while asynchronous does not.

Foreground processing will run synchronously for two reasons:

1)      The administrator forces synchronous processing through a policy setting. This can be done by enabling the Computer Configuration\Policies\Administrative Templates\System\Logon\Always wait for the network at computer startup and logon policy setting. Enabling this setting will make all foreground processing synchronous. This is commonly used for troubleshooting problems with Group Policy processing, but doesn’t always get turned back off again.

Note: For more information on fast logon optimization see:
305293 Description of the Windows Fast Logon Optimization feature
http://support.microsoft.com/kb/305293

2)      A particular CSE requires synchronous foreground processing. There are four CSEs provided by Microsoft that currently require synchronous foreground processing: Software Installation, Folder Redirection, Microsoft Disk Quota and GP Preferences Drive Mapping. If any of these are enabled within one or more GPOs, they will trigger the next foreground processing cycle to run synchronously when they are changed.

Action : Avoid synchronous CSEs and don’t force synchronous policy. If usage of synchronous CSEs is necessary, minimize changes to these policy settings.

Analysis - Starting to read into the gpsvc log
Starting to read into the gpsvc log

First, we identify where the machine settings are starting, because they process first:

GPSVC(31c.37c) 10:01:57:101 CStatusMessage::UpdateWinlogonStatusMessage::++ (bMachine: 1)
GPSVC(31c.37c) 10:01:57:101 Message Status = <Applying computer settings>
GPSVC(31c.37c) 10:01:57:101 User SID = MACHINE SID
GPSVC(31c.37c) 10:01:57:101 Setting GPsession state = 1
GPSVC(31c.174) 10:01:57:101 CGroupPolicySession::ApplyGroupPolicyForPrincipal ::++ (bTriggered: 0, bConsole: 0 )

The above lines are quite clear, “<Applying computer settings>” and “User SID = MACHINE SID” pointing out we are talking about machine context. From the “bConsole: 0” part, which means “Boolean Console” with a value of 0, as in false, meaning no user – machine processing.

GPSVC(31c.174) 10:01:57:101 Waiting for connectivity before applying policies
GPSVC(31c.174) 10:01:57:116 CGPApplicationService::MachinePolicyStartedWaitingOnNetwork.
GPSVC(31c.564) 10:01:57:804 NlaGetIntranetCapability returned Not Ready error. Consider it as NOT intranet capable.
GPSVC(31c.564) 10:01:57:804 There is no connectivity. Waiting for connectivity again...
GPSVC(31c.564) 10:01:59:319 There is connectivity.
GPSVC(31c.564) 10:01:59:319 Wait For Connectivity: Succeeded
GPSVC(31c.174) 10:01:59:319 We have network connectivity... proceeding to apply policy.

This shows us that, at this moment in time, the machine does not have connectivity. However, it does state that it is going to wait for connectivity before applying the policies. After two seconds, we can see that it does find connectivity and moves on with GPO processing.
It is important to understand that there is a default timeout when waiting for connectivity. The default value is 30 seconds, which is configurable.

Connectivity
Now let’s check a bad case scenario where there won’t be a connection available and we run into a timeout:

GPSVC(324.148) 04:58:34:301 Waiting for connectivity before applying policies
GPSVC(324.578) 04:59:04:301 CConnectivityWatcher::WaitForConnectivity: Failed WaitForSingleObject.
GPSVC(324.148) 04:59:04:301 Wait for network connectivity timed out... proceeding to apply policy.
GPSVC(324.148) 04:59:04:301 CGroupPolicySession::ApplyGroupPolicyForPrincipal::ApplyGroupPolicy (dwFlags: 7).
GPSVC(324.148) 04:59:04:317 Application complete with bConnectivityFailure = 1.

As we can see, after 30 seconds it is failing with a timeout and then proceeds to apply policies.
Without a network connection there are no policies from the domain and no version checks between cached ones and domain ones that can be made.
In such cases, you will always encounter “bConnectivityFailure = 1”, which isn’t only typical to a general network connectivity issue, but also for every connectivity problem that the machine encounters, LDAP bind as an example.

Slow Link Detection

GPSVC(31c.174) 10:01:59:397 GetDomainControllerConnectionInfo: Enabling bandwidth estimate.
GPSVC(31c.174) 10:01:59:397 Started bandwidth estimation successfully
GPSVC(31c.174) 10:01:59:976 Estimated bandwidth : DestinationIP = 192.168.1.102
GPSVC(31c.174) 10:01:59:976 Estimated bandwidth : SourceIP = 192.168.1.105
GPSVC(31c.174) 10:02:00:007 IsSlowLink: Bandwidth Threshold (WINLOGON) = 500.
GPSVC(31c.174) 10:02:00:007 IsSlowLink: Bandwidth Threshold (SYSTEM) = 500.
GPSVC(31c.174) 10:02:00:007 IsSlowLink: WWAN Policy (SYSTEM) = 0.
GPSVC(31c.174) 10:02:00:007 IsSlowLink: Current Bandwidth >= Bandwidth Threshold.

Moving further, we can see that a bandwidth estimation is taking place, since Vista, this is done through Network Location Awareness ( NLA ).

Slow Link Detection Backgrounder from our very own " Group Policy Slow Link Detection using Windows Vista and later "

The Group Policy service begins bandwidth estimation after it successfully locates a domain controller. Domain controller location includes the IP address of the domain controller. The first action performed during bandwidth estimation is an authenticated LDAP connect and bind to the domain controller returned during the DC Locator process .

This connection to the domain controller is done under the user's security context and uses Kerberos for authentication. This connection does not support using NTLM. Therefore, this authentication sequence must succeed using Kerberos for Group Policy to continue to process. Once successful, the Group Policy service closes the LDAP connection. The Group Policy service makes an authenticated LDAP connection in computer context when user policy processing is configured in loopback-replace mode.

The Group Policy service then determines the network name. The service accomplishes this by using IPHelper APIs to determine the best network interface in which to communicate with the IP address of the domain controller. Additionally, the domain controller and network name are saved in the client computer's registry for future use.

The Group Policy service is ready to determine the status of the link between the client computer and the domain controller. The service asks NLA to report the estimated bandwidth it measured while earlier Group Policy actions occurred. The Group Policy service compares the value returned by NLA to the GroupPolicyMinTransferRate named value stored in Registry.

The default minimum transfer rate to measure Group Policy slow link is 500 (Kbps). The link between the domain controller and the client is slow if the estimated bandwidth returned by NLA is lower than the value stored in the registry. The policy value has precedence over the preference value if both values appear in the registry. After successfully determining the link state (fast or slow—no errors), then the Group Policy service writes the slow link status into the Group Policy history, which is stored in the registry. The named value is IsSlowLink .

If the Group Policy service encounters an error, it read the last recorded value from the history key and uses that true or false value for the slow link status.

There is updated client-side behavior with Windows 8.1 and later:
What's New in Group Policy in Windows Server - Policy Caching

In Windows Server 2012 R2 and Windows 8.1 , when Group Policy gets the latest version of a policy from the domain controller, it writes that policy to a local store. Then if Group Policy is running in synchronous mode the next time the computer reboots, it reads the most recently downloaded version of the policy from the local store, instead of downloading it from the network. This reduces the time it takes to process the policy. Consequently, the boot time is shorter in synchronous mode. This is especially important if you have a latent connection to the domain controller, for example, with DirectAccess or for computers that are off premises. This behavior is controllable by a new policy called Configure Group Policy Caching.

- The updated slow link detection only takes place during synchronous policy processing. It “pings” the Domain Controller with calling DsGetDcName and measures the duration.

- By default, the Configure Group Policy Caching group policy setting is set to Not Configured. The feature will be enabled by default and using the default values for slow link detection (500ms) and time-out for communicating with a Domain Controller (5000ms) to determine whether it is on the network, if the below conditions are met:

o The Turn off background refresh of Group Policy policy setting is Not Configured or Disabled.

o The Configure Group Policy slow link detection policy setting is Not Configured, or, when Enabled, contains a value for Connection speed (Kbps) that is not outlandish (500 is the default value).

o The Set Group Policy refresh interval for computers is Not Configured or, when Enabled, contains values for Minutes that are not outlandish (90 and 30 at the default values).

Order of processing settings
Next on the agenda is retrieving GPOs from the domain. Here we have Group Policy processing and precedence, Group Policy objects that apply to a user (or computer) do not have the same precedence.
Settings that are applied later can override settings that are applied earlier. The policies are applied in the hierarchy --> Local machine, Sites, Domains and Organizational Units (LSDOU).
For nested organizational units, GPOs linked to parent organizational units are applied before GPOs linked to child organizational units are applied.

Note : The order in which GPOs are processed is significant because when policy is applied, it overwrites policy that was applied earlier.

There are of course some exceptions to the rule:

• A GPO link may be enforced , or disabled , or both.
• A GPO may have its user settings disabled, its computer settings disabled, or all settings disabled.
• An organizational unit or a domain may have Block Inheritance set.
• Loopback may be enabled.

For a better understanding regarding these, please have a look in the following TechNet article: http:// technet.microsoft.com/en-us/library/bb742376.aspx

How does the order of processing look in a gpsvc log
In the gpsvc log you will notice that the ldap search is done starting at the OU level and up to the site level.

"The Group Policy service uses the distinguished name of the computer or user to determine the list of OUs and the domain it must search for group policy objects. The Group Policy service builds this list by analyzing the distinguished name from left to right. The service scans the name looking for each instance of OU= in the name. The service then copies the distinguished name to a list, which is used later. The Group Policy service continues to scan the distinguished name for OUs until it encounters the first instance of DC=. At this point, the Group Policy service has found the domain name, finally it searches for policies at site level."

As you have probably noticed in our example, we only have two GPOs, one at the OU level and one at the Domain level.

The searches are done using the policies GUID and not their name, the same way you would find them in Sysvol, not by name but by their policy GUID.
It is always a best practice to be aware of the policy name and its GUID, thus making it easier to work with, while troubleshooting.

GPSVC(31c.174) 10:01:59:413 GetGPOInfo: Entering...
GPSVC(31c.174) 10:01:59:413 GetMachineToken: Looping for authentication again.
GPSVC(31c.174) 10:01:59:413 SearchDSObject: Searching <OU=Workstations,DC=contoso,DC=lab>
GPSVC(31c.174) 10:01:59:413 SearchDSObject: Found GPO(s) : <[LDAP://cn={CC02524C-727C-4816-A298-
63D12E68C0F},cn=policies,cn=system,DC=contoso,DC=lab; 0 ]>
GPSVC(31c.174) 10:01:59:413 ProcessGPO(Machine): ==============================
GPSVC(31c.174) 10:01:59:413 ProcessGPO(Machine): Deferring search for LDAP://cn={CC02524C-727C-4816-A298-63D12E68C0F},cn=policies,cn=system,DC=contoso,DC=lab
GPSVC(31c.174) 10:01:59:413 SearchDSObject: Searching <DC=contoso,DC=lab>
GPSVC(31c.174) 10:01:59:413 SearchDSObject: Found GPO(s) : <[LDAP://CN={31B2F340-016D-11D2-945F-00C04FB984F9},CN=Policies,CN=System,DC=contoso,DC=lab; 0 ]>
GPSVC(31c.174) 10:01:59:413 ProcessGPO(Machine): ==============================
GPSVC(31c.174) 10:01:59:413 ProcessGPO(Machine): Deferring search for LDAP://CN={31B2F340-016D-11D2-945F-00C04FB984F9},CN=Policies,CN=System,DC=contoso,DC=lab
GPSVC(31c.174) 10:01:59:522 SearchDSObject: Searching <CN=Default-First-Site-Name,CN=Sites,CN=Configuration,DC=contoso,DC=lab>
GPSVC(31c.174) 10:01:59:522 SearchDSObject: No GPO(s) for this object.

You can see if the policy is enabled, disable or enforced here:

GPSVC(31c.174) 10:01:59:413 SearchDSObject: Searching <OU=Workstations,DC=contoso,DC=lab>
GPSVC(31c.174) 10:01:59:413 SearchDSObject: Found GPO(s) : <[LDAP://cn={CC02524C-727C-4816-A298-D63D12E68C0F},cn=policies,cn=system,DC=contoso,DC=lab; 0 ]>

Note the 0 at the end of the ldap query, this is the default setting. If the value were 1 instead of 0 it would mean the policy is set to disabled. In other words, a value of 1 means the policy is linked to that particular OU, domain, or site level but is disabled. If the value is set to 2 then it would mean that the policy has been set to “Enforced.”

A setting of “Enforced” means that if two separate GPOs have the same setting defined, but hold different values, the one that is set to “Enforced” will win and will be applied to the client. If a policy is set to “Enforced” at an OU/domain level and an OU below that is set to block inheritance, then the policy set for “Enforced” will still apply. You cannot block a policy from applying if “Enforced” has been set.

Example of an enforced policy:

GPSVC(328.7fc) 07:01:14:334 SearchDSObject: Searching <OU=Workstations,DC=contoso,DC=lab>
GPSVC(328.7fc) 07:01:14:334 SearchDSObject: Found GPO(s): <[LDAP://cn={CC02524C-727C-4816-A298-D63D12E68C0F},cn=policies,cn=system,DC=contoso,DC=lab; 2 ]>
GPSVC(328.7fc) 07:01:14:334 AllocGpLink: GPO cn={CC02524C-727C-4816-A298-D63D12E68C0F},cn=policies,cn=system,DC=contoso,DC=lab has enforced link.
GPSVC(328.7fc) 07:01:14:334 ProcessGPO(Machine): ==============================

Now let‘s move down the log and we‘ll find the next step where the policies are being processed:

GPSVC(31c.174) 10:02:00:007 ProcessGPO(Machine): ==============================
GPSVC(31c.174) 10:02:00:007 ProcessGPO(Machine): Searching <CN={31B2F340-016D-11D2-945F-00C04FB984F9},CN=Policies,CN=System,DC=contoso,DC=lab>
GPSVC(31c.174) 10:02:00:007 ProcessGPO(Machine): Machine has access to this GPO.
GPSVC(31c.174) 10:02:00:007 ProcessGPO(Machine): Found common name of: <{31B2F340-016D-11D2-945F-00C04FB984F9}>
GPSVC(31c.174) 10:02:00:007 ProcessGPO(Machine): GPO passes the filter check.
GPSVC(31c.174) 10:02:00:007 ProcessGPO(Machine): Found functionality version of: 2
GPSVC(31c.174) 10:02:00:007 ProcessGPO(Machine): Found file system path of: \\contoso.lab\sysvol\contoso.lab\Policies\{31B2F340-016D-11D2-945F-00C04FB984F9}
GPSVC(31c.174) 10:02:00:038 ProcessGPO(Machine): Found display name of: <Default Domain Policy>
GPSVC(31c.174) 10:02:00:038 ProcessGPO(Machine): Found machine version of: GPC is 17, GPT is 17
GPSVC(31c.174) 10:02:00:038 ProcessGPO(Machine): Found flags of: 0
GPSVC(31c.174) 10:02:00:038 ProcessGPO(Machine): Found extensions: [{35378EAC-683F-11D2-A89A-00C04FBBCFA2}{53D6AB1B-2488-11D1-A28C-00C04FB94F17}{53D6AB1D-2488-11D1-A28C-00C04FB94F17}][{827D319E-6EAC-11D2-A4EA-00C04F79F83A}{803E14A0-B4FB-11D0-A0D0-00A0C90F574B}][{B1BE8D72-6EAC-11D2-A4EA-00C04F79F83A}{53D6AB1B-2488-11D1-A28C-00C04FB94F17}{53D6AB1D-2488-11D1-A28C-00C04FB94F17}]
GPSVC(31c.174) 10:02:00:038 ProcessGPO(Machine): ==============================

GPSVC(31c.174) 10:02:00:038 ProcessGPO(Machine): ==============================
GPSVC(31c.174) 10:02:00:038 ProcessGPO(Machine): Searching <cn={CC02524C-727C-4816-A298-D63D12E68C0F},cn=policies,cn=system,DC=contoso,DC=lab>
GPSVC(31c.174) 10:02:00:038 ProcessGPO(Machine): Machine has access to this GPO.
GPSVC(31c.174) 10:02:00:038 ProcessGPO(Machine): Found common name of: <{CC02524C-727C-4816-A298-D63D12E68C0F}>
GPSVC(31c.174) 10:02:00:038 ProcessGPO(Machine): GPO passes the filter check.
GPSVC(31c.174) 10:02:00:038 ProcessGPO(Machine): Found functionality version of: 2
GPSVC(31c.174) 10:02:00:038 ProcessGPO(Machine): Found file system path of: \\contoso.lab\SysVol\contoso.lab\Policies\{CC02524C-727C-4816-A298-D63D12E68C0F}
GPSVC(31c.174) 10:02:00:038 ProcessGPO(Machine): Found display name of: <GPO Guide test>
GPSVC(31c.174) 10:02:00:038 ProcessGPO(Machine): Found machine version of: GPC is 1, GPT is 1
GPSVC(31c.174) 10:02:00:038 ProcessGPO(Machine): Found flags of: 0
GPSVC(31c.174) 10:02:00:038 ProcessGPO(Machine): Found extensions: [{35378EAC-683F-11D2-A89A-00C04FBBCFA2}{D02B1F72-3407-48AE-BA88-E8213C6761F1}]
GPSVC(31c.174) 10:02:00:038 ProcessGPO(Machine): ==============================

First, we find the path where the GPO is stored in AD. As you can see, the GPO is still being represented by the GPO GUID and not its name: Searching <cn={CC02524C-727C-4816-A298-D63D12E68C0F},cn=policies,cn=system,DC=contoso,DC=lab>
After that, it checks to see if the machine has access to the policy, if yes then the computer can apply the policy; if it does not have access, then he cannot apply it. As per example: Machine has access to this GPO.

Moving on, if a policy has a WMI filter being applied, it will be verified in order to see if the filter matches the current machine\user or not.
The WMI filter can be found in AD. If you are using GPMC, then this can be found in the right hand pane at the very bottom box, after highlighting the policy. From our example: GPO passes the filter check.

Functionality version has to be a 2 for a Windows 2003 or later OS to apply the policy. From our example: Found functionality version of: 2
A search in Sysvol for the GPO is also being executed, as explained in the beginning, both AD and Sysvol must be aware of the GPO and its settings. From our example: Found file system path of: <\\contoso.lab\SysVol\contoso.lab\Policies\{CC02524C-727C-4816-A298-D63D12E68C0F}>

The next part is where we check the GPC (Group Policy Container, AD) and the GPT (Group Policy Template, Sysvol) for the version numbers. We check the version numbers to determine if the policy has changed since the last time it was applied. If the version numbers are different (GPC different than GPT) then we either have an AD replication or File replication problem. From our example we can see that there’s a match between those two: Found machine version of: GPC is 1, GPT is 1

The extensions in the next line refers to the CSE (client-side extensions GUIDs) and will vary from policy to policy. As explained, they are the ones in charge at the client side to carry on our settings: From our example: GPSVC(31c.174) 10:02:00:038 ProcessGPO(Machine): Found extensions: [{35378EAC-683F-11D2-A89A-00C04FBBCFA2}{D02B1F72-3407-48AE-BA88-E8213C6761F1}]

Let‘s have a look at an example with a WMI Filter being used, which does not suit our current system:

GPSVC(328.7fc) 08:04:32:803 ProcessGPO(Machine): ==============================
GPSVC(328.7fc) 08:04:32:803 ProcessGPO(Machine): Searching <cn={CC02524C-727C-4816-A298-D63D12E68C0F},cn=policies,cn=system,DC=contoso,DC=lab>
GPSVC(328.7fc) 08:04:32:803 ProcessGPO(Machine): Machine has access to this GPO.
GPSVC(328.7fc) 08:04:32:803 ProcessGPO(Machine): Found common name of: <{CC02524C-727C-4816-A298-D63D12E68C0F}> GPSVC(328.7fc) 08:04:32:803 FilterCheck: Found WMI Filter id of: <[contoso.lab;{CD718707-ACBD-4AD7-8130-05D61C897783};0]>
GPSVC(328.7fc) 08:04:32:913 ProcessGPO(Machine): The GPO does not pass the filter check and so will not be applied.
GPSVC(328.7fc) 08:04:32:913 ProcessGPO(Machine): Found functionality version of: 2
GPSVC(328.7fc) 08:04:32:913 ProcessGPO(Machine): Found file system path of: \\contoso.lab\SysVol\contoso.lab\Policies\{CC02524C-727C-4816-A298-D63D12E68C0F}
GPSVC(328.7fc) 08:04:32:928 ProcessGPO(Machine): Found display name of: <GPO Guide test>
GPSVC(328.7fc) 08:04:32:928 ProcessGPO(Machine): Found machine version of: GPC is 1, GPT is 1
GPSVC(328.7fc) 08:04:32:928 ProcessGPO(Machine): Found flags of: 0
GPSVC(328.7fc) 08:04:32:928 ProcessGPO(Machine): Found extensions: [{35378EAC-683F-11D2-A89A-00C04FBBCFA2}{D02B1F72-3407-48AE-BA88-E8213C6761F1}]
GPSVC(328.7fc) 08:04:32:928 ProcessGPO(Machine): ==============================

In this scenario a WMI filter was used, which specifies that the used OS has to be Windows XP, so in order to apply the GPO the system OS has to match our filter. As our OS is Windows 2012R2, the filter does not match and so the GPO will not apply.

Now we come to the part where we process CSE’s for particular settings, such as Folder Redirection, Disk Quota, etc. If the particular extension is not being used then you can simply ignore this section.

GPSVC(31c.174) 10:02:00:038 ProcessGPOs(Machine): Get 2 GPOs to process.
GPSVC(31c.174) 10:02:00:038 ReadExtStatus: Reading Previous Status for extension {35378EAC-683F-11D2-A89A-00C04FBBCFA2}
GPSVC(31c.174) 10:02:00:038 ReadStatus: Read Extension's Previous status successfully.
GPSVC(31c.174) 10:02:00:038 ReadExtStatus: Reading Previous Status for extension {0ACDD40C-75AC-47ab-BAA0-BF6DE7E7FE63}
GPSVC(31c.174) 10:02:00:038 ReadExtStatus: Reading Previous Status for extension {0E28E245-9368-4853-AD84-6DA3BA35BB75}
GPSVC(31c.174) 10:02:00:038 ReadExtStatus: Reading Previous Status for extension {16be69fa-4209-4250-88cb-716cf41954e0} GPSVC(31c.174) 10:02:00:038 ReadExtStatus: Reading Previous Status for extension {17D89FEC-5C44-4972-B12D-241CAEF74509}
GPSVC(31c.174) 10:02:00:038 ReadExtStatus: Reading Previous Status for extension {1A6364EB-776B-4120-ADE1-B63A406A76B5}
GPSVC(31c.174) 10:02:00:038 ReadExtStatus: Reading Previous Status for extension {25537BA6-77A8-11D2-9B6C-0000F8080861}
GPSVC(31c.174) 10:02:00:038 ReadExtStatus: Reading Previous Status for extension {3610eda5-77ef-11d2-8dc5-00c04fa31a66} GPSVC(31c.174) 10:02:00:038 ReadExtStatus: Reading Previous Status for extension {3A0DBA37-F8B2-4356-83DE-3E90BD5C261F}
GPSVC(31c.174) 10:02:00:038 ReadExtStatus: Reading Previous Status for extension {426031c0-0b47-4852-b0ca-ac3d37bfcb39} GPSVC(31c.174) 10:02:00:038 ReadExtStatus: Reading Previous Status for extension {42B5FAAE-6536-11d2-AE5A-0000F87571E3} GPSVC(31c.174) 10:02:00:038 ReadExtStatus: Reading Previous Status for extension {4bcd6cde-777b-48b6-9804-43568e23545d} GPSVC(31c.174) 10:02:00:038 ReadExtStatus: Reading Previous Status for extension {4CFB60C1-FAA6-47f1-89AA-0B18730C9FD3}
GPSVC(31c.174) 10:02:00:038 ReadExtStatus: Reading Previous Status for extension {4D2F9B6F-1E52-4711-A382-6A8B1A003DE6}
GPSVC(31c.174) 10:02:00:038 ReadExtStatus: Reading Previous Status for extension {5794DAFD-BE60-433f-88A2-1A31939AC01F}
GPSVC(31c.174) 10:02:00:038 ReadExtStatus: Reading Previous Status for extension {6232C319-91AC-4931-9385-E70C2B099F0E} GPSVC(31c.174) 10:02:00:038 ReadExtStatus: Reading Previous Status for extension {6A4C88C6-C502-4f74-8F60-2CB23EDC24E2} GPSVC(31c.174) 10:02:00:038 ReadExtStatus: Reading Previous Status for extension {7150F9BF-48AD-4da4-A49C-29EF4A8369BA}
GPSVC(31c.174) 10:02:00:038 ReadExtStatus: Reading Previous Status for extension {728EE579-943C-4519-9EF7-AB56765798ED} GPSVC(31c.174) 10:02:00:038 ReadExtStatus: Reading Previous Status for extension {74EE6C03-5363-4554-B161-627540339CAB} GPSVC(31c.174) 10:02:00:038 ReadExtStatus: Reading Previous Status for extension {7B849a69-220F-451E-B3FE-2CB811AF94AE} GPSVC(31c.174) 10:02:00:038 ReadExtStatus: Reading Previous Status for extension {827D319E-6EAC-11D2-A4EA-00C04F79F83A}

Note:

• You can always do a search for each of these GUIDs on MSDN and you should be able to find their proper names.
• At the end of the machine GPO thread, we can also see the Foreground processing that we talked about in the beginning. We can see that the Foreground processing was Synchronous and that the next one will be Synchronous as well.
• The end of the machine GPO processing thread comes to an end and we can see that it was completed with a bConnectivityFailure = 0.

GPSVC(31c.174) 10:02:00:397 ProcessGPOs(Machine): SKU is SYNC: Mode: 1, Reason: 7
GPSVC(31c.174) 10:02:00:397 gpGetFgPolicyRefreshInfo (Machine): Mode: Synchronous , Reason: 7
GPSVC(31c.174) 10:02:00:397 gpSetFgPolicyRefreshInfo (bPrev: 1, szUserSid: Machine, info.mode: Synchronous)
GPSVC(31c.174) 10:02:00:397 SetFgRefreshInfo: Previous Machine Fg policy Synchronous, Reason: SKU.
GPSVC(31c.174) 10:02:00:397 gpSetFgPolicyRefreshInfo (bPrev: 0, szUserSid: Machine, info.mode: Synchronous)
GPSVC(31c.174) 10:02:00:397 SetFgRefreshInfo: Next Machine Fg policy Synchronous, Reason: SKU.
GPSVC(31c.174) 10:02:00:397 ProcessGPOs(Machine): Policies changed - checking if UBPM trigger events need to be fired
GPSVC(31c.174) 10:02:00:397 CheckAndFireGPTriggerEvent: Fired Policy present UBPM trigger event for Machine.
GPSVC(31c.174) 10:02:00:397 Application complete with bConnectivityFailure = 0.

User GPO Thread

This next part of the GPO log is dedicated to the user thread.

While the machine thread had the TID (31c. 174 ) the user thread has (31c. b8 ) which you can notice when the thread actually starts. You can see that the user SID is found.
Also, notice this time the “ bConsole: 1 ” at the end instead of 0 which we had for the machine.

GPSVC(31c.704) 10:02:47:147 CGPEventSubSystem:: GroupPolicyOnLogon ::++ (SessionId: 1)
GPSVC(31c.704) 10:02:47:147 CGPApplicationService:: UserLogonEvent ::++ (SessionId: 1, ServiceRestart: 0)
GPSVC(31c.704) 10:02:47:147 CGPApplicationService:: CheckAndCreateCriticalPolicySection.
GPSVC(31c.704) 10:02:47:147 User SID = <S-1-5-21-646618010-1986442393-1057151281-1103>
GPSVC(31c.b8) 10:02:47:147 CGroupPolicySession::ApplyGroupPolicyForPrincipal ::++ (bTriggered: 0, bConsole: 1 )

You can see that it does the network check again and that it is also prepared to wait for network.

GPSVC(31c.b8) 10:02:47:147 CGPApplicationService:: GetTimeToWaitOnNetwork.
GPSVC(31c.b8) 10:02:47:147 CGPMachineStartupConnectivity::CalculateWaitTimeoutFromHistory: Average is 3334.
GPSVC(31c.b8) 10:02:47:147 CGPMachineStartupConnectivity::CalculateWaitTimeoutFromHistory: Current is 2203.
GPSVC(31c.b8) 10:02:47:147 CGPMachineStartupConnectivity::CalculateWaitTimeoutFromHistory: Taking min of 6668 and 120000.
GPSVC(31c.b8) 10:02:47:147 CGPApplicationService:: GetStartTimeForNetworkWait.
GPSVC(31c.b8) 10:02:47:147 StartTime For network wait: 3750ms

In this case it decides to wait for network with timeout 0 ms because it already has network connectivity and so moves on to processing GPOs.

GPSVC(31c.b8) 10:02:47:147 UserPolicy: Waiting for machine policy wait for network event with timeout 0 ms
GPSVC(31c.b8) 10:02:47:147 CGroupPolicySession::ApplyGroupPolicyForPrincipal::ApplyGroupPolicy (dwFlags: 38).

The next part remains the same as for the machine thread, it searches and returns networks found, number of interfaces and bandwidth check.

GPSVC(31c.b8) 10:02:47:147 NlaQueryNetSignatures returned 1 networks
GPSVC(31c.b8) 10:02:47:147 NSI Information (Network GUID) : {1F777393-0B42-11E3-80AD-806E6F6E6963}
GPSVC(31c.b8) 10:02:47:147 # of interfaces : 1
GPSVC(31c.b8) 10:02:47:147 Interface ID: {9869CFDA-7F10-4B3F-B97A-56580E30CED7}
GPSVC(31c.b8) 10:02:47:163 GetDomainControllerConnectionInfo: Enabling bandwidth estimate.
GPSVC(31c.b8) 10:02:47:475 Started bandwidth estimation successfully
GPSVC(31c.b8) 10:02:47:851 IsSlowLink: Current Bandwidth >= Bandwidth Threshold.

The ldap query for the GPOs is done in the same manner as for the machine thread:

GPSVC(31c.b8) 10:02:47:490 GetGPOInfo: Entering...
GPSVC(31c.b8) 10:02:47:490 SearchDSObject: Searching <OU=Admin Users,DC=contoso,DC=lab>
GPSVC(31c.b8) 10:02:47:490 SearchDSObject: Found GPO(s): <[LDAP://cn={CCF581E3-E2ED-441F-B932-B78A3DFAE09B},cn=policies,cn=system,DC=contoso,DC=lab; 0 ]>
GPSVC(31c.b8) 10:02:47:490 ProcessGPO(User): ==============================
GPSVC(31c.b8) 10:02:47:490 ProcessGPO(User): Deferring search for LDAP://cn={CCF581E3-E2ED-441F-B932-B78A3DFAE09B},cn=policies,cn=system,DC=contoso,DC=lab
GPSVC(31c.b8) 10:02:47:490 SearchDSObject: Searching <DC=contoso,DC=lab>
GPSVC(31c.b8) 10:02:47:490 SearchDSObject: Found GPO(s): <[LDAP://CN={31B2F340-016D-11D2-945F-00C04FB984F9},CN=Policies,CN=System,DC=contoso,DC=lab; 0 ]>
GPSVC(31c.b8) 10:02:47:490 ProcessGPO(User): ==============================
GPSVC(31c.b8) 10:02:47:490 ProcessGPO(User): Deferring search for LDAP://CN={31B2F340-016D-11D2-945F-00C04FB984F9},CN=Policies,CN=System,DC=contoso,DC=lab
GPSVC(31c.b8) 10:02:47:490 SearchDSObject: Searching <CN=Default-First-Site-Name,CN=Sites,CN=Configuration,DC=contoso,DC=lab>
GPSVC(31c.b8) 10:02:47:490 SearchDSObject: No GPO(s) for this object.
GPSVC(31c.b8) 10:02:47:490 EvaluateDeferredGPOs: Searching for GPOs in cn=policies,cn=system,DC=contoso,DC=lab
GPSVC(31c.b8) 10:02:47:490 EvaluateDeferredGPOs: Adding filters (&(!(flags:1.2.840.113556.1.4.803:=1))(gPCUserExtensionNames=[*])((|(distinguishedName=CN={31B2F340-016D-11D2-945F-00C04FB984F9},CN=Policies,CN=System,DC=contoso,DC=lab)(distinguishedName=cn={CCF581E3-E2ED-441F-B932-B78A3DFAE09B},cn=policies,cn=system,DC=contoso,DC=lab))))

We can see the GPOs are processed exactly as explained in the machine part, while the difference is that the GPO has to be available for the user this time and not the machine. The important thing in the following example is that the Default Domain Policy (we know it is the Default Domain Policy because it has a hardcoded GUID {31B2F340-016D-11D2-945F-00C04FB984F9 } which will be that same in every Domain) contains no extensions for the user side, thus being reported to us “ has no extensions ”:

GPSVC(31c.b8) 10:02:47:851 EvalList: Object <CN= {31B2F340-016D-11D2-945F-00C04FB984F9}, CN=Policies,CN=System,DC=contoso,DC=lab> cannot be accessed/is disabled/ or has no extensions
GPSVC(31c.b8) 10:02:47:851 ProcessGPO(User): ==============================
GPSVC(31c.b8) 10:02:47:851 ProcessGPO(User): Searching <cn={CCF581E3-E2ED-441F-B932-B78A3DFAE09B},cn=policies,cn=system,DC=contoso,DC=lab>
GPSVC(31c.b8) 10:02:47:851 ProcessGPO(User): User has access to this GPO.
GPSVC(31c.b8) 10:02:47:851 ProcessGPO(User): Found common name of: <{CCF581E3-E2ED-441F-B932-B78A3DFAE09B}>
GPSVC(31c.b8) 10:02:47:851 ProcessGPO(User): GPO passes the filter check.
GPSVC(31c.b8) 10:02:47:851 ProcessGPO(User): Found functionality version of: 2
GPSVC(31c.b8) 10:02:47:851 ProcessGPO(User): Found file system path of: \\contoso.lab\SysVol\contoso.lab\Policies\{CCF581E3-E2ED-441F-B932-B78A3DFAE09B}
GPSVC(31c.b8) 10:02:47:851 ProcessGPO(User): Found display name of: <GPO Guide Test Admin Users>
GPSVC(31c.b8) 10:02:47:851 ProcessGPO(User): Found user version of: GPC is 3, GPT is 3
GPSVC(31c.b8) 10:02:47:851 ProcessGPO(User): Found flags of: 0
GPSVC(31c.b8) 10:02:47:851 ProcessGPO(User): Found extensions: [{35378EAC-683F-11D2-A89A-00C04FBBCFA2}{D02B1F73-3407-48AE-BA88-E8213C6761F1}]
GPSVC(31c.b8) 10:02:47:851 ProcessGPO(User): ==============================

After that, our policy settings are processed directly into the registry by the CSE:

GPSVC(318.7ac) 02:02:02:187 SetRegistryValue: NoWindowsMarketplace => 1 [OK]
GPSVC(318.7ac) 02:02:02:187 SetRegistryValue: ScreenSaveActive => 0 [OK]

While moving on to process CSE’s for particular settings, such as Folder Redirection, Disk Quota, etc., exactly as it was done for the machine thread.

Here it is the same as the machine thread, where the user thread is also finished with a bConnectivityFailure = 0 and everything was applied as expected.

GPSVC(31c.b8) 10:02:47:912 User logged in on active session
GPSVC(31c.b8) 10:02:47:912 ApplyGroupPolicy: Getting ready to create background thread GPOThread.
GPSVC(31c.b8) 10:02:47:912 CGroupPolicySession::ApplyGroupPolicyForPrincipal Setting m_pPolicyInfoReadyEvent
GPSVC(31c.b8) 10:02:47:912 Application complete with bConnectivityFailure = 0 .

In the gpsvc log, you will always have a confirmation that the “ problematic ” GPO was indeed processed or not; this is to make sure that the GPO was read and applied from the domain. The registry values that the GPO contains should be applied on the client side by the CSEs, so if you see a GPO in gpsvc getting applied but the desired setting isn’t applied on the client side, it is a good idea to check the registry values yourself by using “regedit” in order to ensure they have been properly set.

If these registry values are getting changed after they have been applied, a good tool provided by Microsoft to further troubleshoot this is Process Monitor , which can be used to follow those certain registry settings and see who’s changing them.

There are definitely all sort of problem scenarios that I haven’t covered with this guide. This is meant as a starter guide for you to have an idea how to follow up if your domain GPOs aren’t getting applied and you want to use our gpsvc log to troubleshoot this.

Finally, as Client Side Extensions (CSE) play a major role for GPO settings distribution, here is a list for those of you that want to go deeper with CSE Logging, which you can enable in order to gather more information about the CSE state:

Scripts and Administrative Templates CSE Debug Logging (gptext.dll) HKLM\Software\Microsoft\WindowsNT\CurrentVersion\Winlogon

ValueName: GPTextDebugLevel
ValueType: REG_DWORD
Value Data: 0x00010002
Options: 0x00000001 = DL_Normal
0x00000002 = DL_Verbose
0x00010000 = DL_Logfile
0x00020000 = DL_Debugger

Log File: C:\WINNT\debug\usermode\gptext.log

Security CSE WINLOGON Debug Logging (scecli.dll)
KB article: 245422 How to Enable Logging for Security Configuration Client Processing in Windows 2000

HKLM\Software\Microsoft\WindowsNT\CurrentVersion\WinLogon\GPExtensions\{827D319E-6EAC-11D2- A4EA-00C04F79F83A

ValueName: ExtensionDebugLevel
ValueType: REG_DWORD
Value Data: 2
Options: 0 = Log Nothing
1 = Log only errors
2 = Log all transactions

Log File: C:\WINNT\security\logs\winlogon.log

Folder Redirection CSE Debug Logging (fdeploy.dll)
HKLM\Software\Microsoft\WindowsNT\CurrentVersion\Diagnostics

ValueName: fdeployDebugLevel
ValueType: REG_DWORD
Value Data: 0x0f

Log File: C:\WINNT\debug\usermode\fdeploy.log

Offline Files CSE Debug Logging (cscui.dll)
KB article: 225516 How to Enable the Offline Files Notifications Window in Windows 2000

Software Installation CSE Verbose logging (appmgmts.dll)
KB article: 246509 Troubleshooting Program Deployment by Using Verbose Logging
HKLM\Software\Microsoft\WindowsNT\CurrentVersion\Diagnostics

ValueName: AppmgmtDebugLevel
ValueType: REG_DWORD
Value Data: 0x9B or 0x4B

Log File: C:\WINNT\debug\usermode\appmgmt.log

Software Installation CSE Windows Installer Verbose logging
KB article: 314852 How to enable Windows Installer logging

HKLM\Software\Policies\Microsoft\Windows\Installer

ValueName: Logging
Value Type: Reg_SZ
Value Data: voicewarmup

Log File: C:\WINNT\temp\MSI*.log

Desktop Standard CSE Debug Logging
KB article: 931066 How to enable tracing for client-side extensions in PolicyMaker

GPEDIT - Group Policy Editor Console Debug Logging
TechNet article: Enabling Logging for Group Policy Editor
HKLM\Software\Microsoft\Windows NT\CurrentVersion\Winlogon

Value Name: GPEditDebugLevel
Value Type: REG_DWORD
Value Data: 0x10002

Log File: %windir%\debug\usermode\gpedit.log

GPMC - Group Policy Management Console Debug Logging
TechNet article: Enable Logging for Group Policy Management Console
HKLM\Software\Microsoft\Windows NT\CurrentVersion\Diagnostics

Value Name: GPMgmtTraceLevel
Value Type: REG_DWORD
Value Data: 2

HKLM\Software\Microsoft\Windows NT\CurrentVersion\Diagnostics

Value Name: GPMgmtLogFileOnly
Value Type: REG_DWORD
Value Data: 1

Log File: C:\Documents and Settings\<user>\Local Settings\Temp\gpmgmt.log

RSOP - Resultant Set of Policies Debug Logging
Debug Logging for RSoP Procedures:
HKEY_LOCAL_MACHINE\Software\Microsoft\Windows NT\CurrentVersion\Winlogon

Value Name: RsopDebugLevel
Value Type: REG_DWORD
Value Data: 0x00010004

Log File: %windir%\system32\debug\USERMODE\GPDAS.LOG

WMI Debug Logging
ASKPERF blog post: WMI Debug Logging

I hope this was interesting and shed some light on how to start analyzing the gpsvc log.

Thank you,

David Ani