Wpkg-GP doesn't get executed on boot

[Jürgen Nagel]

Hi all,

I'm currently evaluating Wpkg-GP for our upcoming Active Directory setup.

Unfortunately I haven't yet been able to get Wpkg-GP executed on boot.

When I execute Wpkg-GP-Test wpkg gets executed properly and the test application gets installed on the local machine:

2014-07-23 13:17:10,020 - WpkgService - DEBUG - DoProcessClient() start

2014-07-23 13:17:10,036 - WpkgService - DEBUG - Config: Reading DisableAtBootUp: '0' from ini file

2014-07-23 13:17:10,036 - WpkgService - INFO - Received 'Execute', executing WPKG

2014-07-23 13:17:10,036 - WpkgService - DEBUG - Checking client acccess

2014-07-23 13:17:10,052 - WpkgService - DEBUG - Client is a member of Administrators group

2014-07-23 13:17:10,068 - WpkgService - DEBUG - Client is a local user

2014-07-23 13:17:10,084 - WpkgService - DEBUG - Config: Reading WpkgExecuteByNonAdmins: '0' from ini file

2014-07-23 13:17:10,084 - WpkgService - DEBUG - WpkgExecuteByNonAdmins is 0

2014-07-23 13:17:10,084 - WpkgService - DEBUG - Config: Reading WpkgExecuteByLocalUsers: '1' from ini file

2014-07-23 13:17:10,084 - WpkgService - DEBUG - WpkgExecuteByLocalUsers is 1

2014-07-23 13:17:10,084 - WpkgService - DEBUG - Client user is a member of Administrators group, permission is granted

2014-07-23 13:17:10,084 - WpkgService - INFO - Executing WPKG with the command cscript \\adfileserver\wpkg\wrapper.js /noreboot /synchronize /sendStatus /nonotify /quiet

2014-07-23 13:17:10,084 - WpkgService - DEBUG - Config: Returning default value TestConnectionHost: 'None' as it is not configured

2014-07-23 13:17:10,084 - WpkgService - DEBUG - Config: Returning default value ConnectionSleepBeforeRetry: '5' as it is not configured

2014-07-23 13:17:10,084 - WpkgService - DEBUG - Config: Returning default value ConnectionTries: '7' as it is not configured

2014-07-23 13:17:10,084 - WpkgService - DEBUG - Trying to connect to share. 1 of 7

2014-07-23 13:17:10,801 - WpkgService - INFO - Successfully connected to \\adfileserver\wpkg as AD\wpkg

2014-07-23 13:17:10,801 - WpkgService - DEBUG - Reading EnvironmentVariables from ini file

2014-07-23 13:17:10,816 - WpkgService - DEBUG - Config: Reading WpkgActivityIndicator: '1' from ini file

2014-07-23 13:17:16,680 - WpkgService - INFO - Trying to disconnect from the network share \\adfileserver\wpkg

2014-07-23 13:17:16,680 - WpkgService - INFO - Successfully disconnected from the network

2014-07-23 13:17:16,680 - WpkgService - INFO - Finished executing Wpkg.js

On boot however, nothing happens. Wpkg-GP doesn't even get mentioned.

According to the logs Wpkg-GP doesn't attempt to connect to the share and execute wpkg:

2014-07-23 13:39:15,437 - WpkgService - INFO - Logging started with verbosity: 3

2014-07-23 13:39:15,451 - WpkgService - DEBUG - LGP: Opening C:\Windows\system32\GroupPolicy\gpt.ini

2014-07-23 13:39:15,451 - WpkgService - DEBUG - Config: Reading EnableViaLGP: '1' from ini file

2014-07-23 13:39:15,451 - WpkgService - DEBUG - Config: Reading WpkgCommand: '\\adfileserver\wpkg\wrapper.js' from ini file

2014-07-23 13:39:15,451 - WpkgService - DEBUG - Config: Reading WpkgCommand: '\\adfileserver\wpkg\wrapper.js' from ini file

2014-07-23 13:39:15,451 - WpkgService - DEBUG - Trying to extract share name from \\adfileserver\wpkg\wrapper.js

2014-07-23 13:39:15,451 - WpkgService - DEBUG - Extracted share: '\\adfileserver\wpkg'

2014-07-23 13:39:15,451 - WpkgService - DEBUG - Config: Reading WpkgNetworkUsername: 'AD\wpkg' from ini file

2014-07-23 13:39:15,451 - WpkgService - DEBUG - Reading WpkgNetworkPassword from ini file

2014-07-23 13:39:15,529 - WpkgService - DEBUG - Config: Reading WpkgMaxReboots: '10' from ini file

2014-07-23 13:39:15,529 - WpkgService - DEBUG - Config: Reading WpkgRebootPolicy: 'force' from ini file

2014-07-23 13:39:15,529 - WpkgService - DEBUG - WpkgCommand is a js file but is missing 'cscript', adding

2014-07-23 13:39:15,529 - WpkgService - DEBUG - WpkgCommand is a js but is missing /noreboot, adding

2014-07-23 13:39:15,529 - WpkgService - DEBUG - WpkgCommand is a js but is missing /synchronize, adding

2014-07-23 13:39:15,529 - WpkgService - DEBUG - WpkgCommand is a js but is missing /sendStatus, adding

2014-07-23 13:39:15,529 - WpkgService - DEBUG - WpkgCommand is a js but is missing /nonotify, adding

2014-07-23 13:39:15,529 - WpkgService - DEBUG - WpkgCommand is a js but is missing /quiet, adding

Do you have any idea what I might be doing wrong?

Regards, Juergen

[Jürgen Nagel]

Here's some more information I found out...

To debug the issue I enabled the UserEnv logging and found the following in the gpsvc.log:

GPSVC(17c.a00) 17:30:40:929 ProcessGPOs: -----------------------

GPSVC(17c.a00) 17:30:40:929 ProcessGPOs: Processing extension Wpkg-GP

GPSVC(17c.a00) 17:30:40:929 CompareGPOLists:  The lists are the same.

GPSVC(17c.a00) 17:30:40:929 CheckGPOs: No GPO changes but couldn't read extension Wpkg-GP's status or policy time.

GPSVC(17c.a00) 17:30:40:929 ProcessGPOs: Extension Wpkg-GP skipped with flags 0x6.

GPSVC(17c.a00) 17:30:40:929 ProcessGPOs: -----------------------

I haven't yet been able to find out what "skipped with flags 0x6" actually means.

Regards, Juergen

[john...@andreini.me]

I just went through this and I got it to work. I think that HKLM\Software\Wpkg-GP has EnableViaLGP set to 1. When the service starts it reads EnableViaLGP=1 from the Wpkg-gp.ini file and checks this against the registry key to see if it is already set. If they both match it does nothing. If they are different it either adds or removes the GPE extension GUID from "C:\Windows\System32\GroupPolicy\gpt.ini." and updates the registry key. So I think it is doing nothing and the gpt.ini file is not getting updated.

So if you set EnableViaLGP to 0 in the registry and then start and stop the service you should see something like the following:

2014-07-23 13:39:15,451 - WpkgService - DEBUG - LGP: Opening C:\Windows\system32\GroupPolicy\gpt.ini

2014-07-23 13:39:15,451 - WpkgService - DEBUG - Config: Reading EnableViaLGP: '1' from ini file

2014-07-23 13:39:15,451 - WpkgService - DEBUG - Adding to LGP

2014-07-23 13:39:15,451 - WpkgService - DEBUG - Config: Reading WpkgCommand: '\\adfileserver\wpkg\wrapper.js' from ini file

2014-07-23 13:39:15,451 - WpkgService - DEBUG - Config: Reading WpkgCommand: '\\adfileserver\wpkg\wrapper.js' from ini file

Rebooting should show Wpkg-GP installing your software.

[John-Paul]

That should be stop and start the service.

[Jürgen Nagel]

Unfortunately that didn't help.

The service did re-add the GPE:

2014-07-28 09:01:22,967 - WpkgService - INFO - Logging started with verbosity: 3

2014-07-28 09:01:22,967 - WpkgService - DEBUG - LGP: Opening C:\Windows\system32\GroupPolicy\gpt.ini

2014-07-28 09:01:22,967 - WpkgService - DEBUG - Config: Reading EnableViaLGP: '1' from ini file

2014-07-28 09:01:22,967 - WpkgService - DEBUG - Adding to LGP

On reboot however, nothing happened. Wpkg-GP wasn't executed and the software package didn't get installed.

The gpt.ini contains the following entries:

[General]

version =5

gpcmachineextensionnames =[{35378EAC-683F-11D2-A89A-00C04FBBCFA2}{D02B1F72-3407-48AE-BA88-E8213C6761F1}][{A9B8D792-F454-11DE-BA92-FDCF56D89593}{0F6B957D-509E-11D1-A7CC-0000F87571E3}]

[John-Paul]

OK. Looking through my own UserEnv logs I see the same GPSVC logs but these are following Wpkg called successfully.

Looks like this:
GPSVC(538.5e4) 09:22:14:935 ProcessGPOs: Processing extension Wpkg-GP
GPSVC(538.5e4) 09:22:14:935 ReadStatus: Read Extension's Previous status successfully.
GPSVC(538.5e4) 09:22:14:935 CompareGPOLists:  The lists are the same.
GPSVC(538.5e4) 09:22:14:935 GPLockPolicySection: Sid = (null), dwTimeout = 30000, dwFlags = 0
GPSVC(538.5e4) 09:22:14:935 LockPolicySection called for user <Machine>
GPSVC(538.5e4) 09:22:14:935 Sync Lock Called
GPSVC(538.5e4) 09:22:14:935 Writer Lock got immediately.
GPSVC(538.5e4) 09:22:14:935 Lock taken successfully
GPSVC(538.5e4) 09:22:14:935 ProcessGPOList: Entering for extension Wpkg-GP
GPSVC(538.5e4) 09:22:14:935 MachinePolicyCallback: Setting status UI to Applying Wpkg-GP policy...
GPSVC(538.5e4) 09:22:14:935 ProcessGPOList: No changes. CSE will not be passed in the IwbemServices intf ptr
GPSVC(538.554) 09:22:14:935 Message Status = <Applying Wpkg-GP policy...>
...

[Jürgen Nagel]

O.K., I think I finally managed to fix the problem.

After some deep digging in the Windows event viewer I stumbled across a warning about the WMI subsystem.

As soon as I had rebuilt the WMI repository and rebooted the machine, all of a sudden the Wpkg-GP extension did get executed.

So, as a tip for all the other people who might struggle with the Wpkg-GP extension not getting executed: search the event viewer for any warnings or errors and fix them, even if they don't relate to Group Policies at first. They might interfere with the GPE subsystem somehow.

Regards, Juergen

[Jorge Albarenque]

Hi Jürgen,

I am facing the exact same issue after unjoining the PCs from one domain and joining them to another one. Could you tell me exactly what you did in order to fix it?

Thanks a lot!

George

[George]

Nevermind, I already figured it out and it was not related to this issue. The wpkg-gp ADMX template was missing the clientExtension definition so it was never called at bootup (already filed a bug report).

Best regards

George