?
Solved

Slow login due to Applying Computer Policy - GPO or Profile timeout issue?

Posted on 2007-07-29
6
Medium Priority
?
2,975 Views
Last Modified: 2012-05-05
On our network login times can vary for no obvious reason, from 2 to 10
minutes. This appears to be an issue with either Group Policy processing or
user profile. This appears to be slowest for the first login during the day,
if the box is rebooted during the day the login time is fine, 30 sec to under
2 minutes.

We are running all Win2k3 DC some using SP1 some not. Clients are XP SP2.  There are four computer and four user policies being applied.

I have logged data in UserEnv.log and it shows that GPO processing seems to
occur quickly, without error. There are long delays in processing the profile
and a mystery unaccounted for section in the log.

It takes nearly 7 minutes for the computer policy to apply on this test PC and 3 seconds to apply the user policy.

09:17:51:093 ApplyGroupPolicy
09:17:51:109 ProcessGPOs: Starting computer Group Policy
09:18:25:437 ProcessGPOs: User name is:
CN=TESTPC,OU=IT_GROUP,OU=DESKTOPS,OU=RESOURCES
09:24:48:877 ProcessGPOs: Leaving with 1

09:24:53:226 ApplyGroupPolicy
09:24:53:336 ProcessGPOs: User name is: CN=TESTUSER,OU= IT_GROUP
09:24:53:711 SearchDSObject: Searching OU= IT_GROUP
09:24:56:606 ProcessGPOs: Leaving with 1

Roaming profiles are being sync down to the clients. GPO has a limit on the Profile size which is enforced by proquota.exe executing on the client, set to 35 MB limit. The My Documents is redirected to the users home directory, so is not taking up space in the roaming profile.

I initially though proquota.exe was causing issues with the profile processing, but ProcMon.exe boot log has shown that proquota.exe is executing late the boot process, after the delay in processing Profile.

Gpupdate /force is timing out after 10 minutes when executing on a client, after ten minutes. I am not sure this issue has the same cause as the slow login behaviour. I created a test user and PC without profile limit set and ran gpupdate /force. My current best theory is that since some roaming profiles have been deleted and recreated with the same behaviour re-appearing there must be some corruption/weirdness in the GP templates.

Without a way to resolve timeouts in GPO and Profile processing to a definite cause, at the moment, my best attempt to solve this is rebuild GPO from scratch (giving me a clean GPO) and retest the behaviour. Unless some else has a bright idea.

This problem is driving me crazy. How the hell can I identify profile
corruption/timeout or GPO timeout issues easily during login?

I have logged log in event using Group Policy core (UserEnv) and registry
CSE logging in %windir%\debug\usermode\UserEnv.log. Set registry key
HKEY_LOCAL_MACHINE\Software\Microsoft\Windows NT\CurrentVersion\Winlogon and
add value UserEnvDebugLevel = REG_DWORD, value 30002.

I logged a client with a login delay, from entry of user name and password
to executing Outlook as Startup program in the profile which covered 8
minutes 2 seconds. a long time to get a usable desktop.

I have used SysInternals Process Monitor (ProcMon.exe) to log during boot
up, but the log is vast and I have not found any useful data in it.

I have simplified the UserEnv.log output below.

Start login
USERENV(494.498) 09:17:41:343 LibMain: Process Name:
\??\C:\WINDOWS\system32\winlogon.exe
34 sec start ProcessGPO and SearchDSObject
09:17:51:093 ApplyGroupPolicy
09:17:51:109 ProcessGPOs: Starting computer Group Policy
09:18:25:437 ProcessGPOs: User name is:
CN=TESTPC,OU=IT_GROUP,OU=DESKTOPS,OU=RESOURCES

49 sec delay MachinePolicyCallback to LoadUserProfile
09:18:28:491 MachinePolicyCallback: Setting status UI to Applying Security
policy
09:18:34:323 MachinePolicyCallback
09:19:17:610 LoadUserProfile

58 sec Delay RecurseDirectory
09:19:19:506 GetExistingLocalProfileImage
09:19:20:462 RecurseDirectory
09:20:18:229 RecurseDirectory

16 Secs Load Profile
09:20:20:016 CopyProfileDirectoryEx : Found hive file NTUSER.DAT
09:20:36:481 LoadUserProfile

251 Sec delay for??
USERENV(494.fc4) 09:20:36:654 IsSyncForegroundPolicyRefresh: Synchronous,
Reason: NonCachedCredentials
USERENV(494.65c) 09:24:47:124 MachinePolicyCallback: Setting status UI to
Applying computer settings...

3 second to apply User Policy
09:24:48:877 ProcessGPOs: Leaving with 1
09:24:53:226 ApplyGroupPolicy
09:24:53:336 ProcessGPOs: User name is: CN=TESTUSER,OU= IT_GROUP
09:24:53:711 SearchDSObject: Searching OU= IT_GROUP
09:24:56:606 ProcessGPOs: Leaving with 1

44 Seconds Profile script to Outlook execution
09:24:59:360 GetProfileType
09:25:00:111 GetUserDNSDomainName: Failed to impersonate user
09:25:03:206 LibMain: Process Name: C:\WINDOWS\system32\wscript.exe
09:25:43:228 LibMain: Process Name: C:\Program Files\Microsoft
Office\Office\OSA9.EXE
0
Comment
Question by:osea
5 Comments
 
LVL 29

Expert Comment

by:Alan Huseyin Kayahan
ID: 19587927
       Hi osea
             Slow login issues at applying computer policy %90 indicates a DNS issue. Check if DNS server is functioning in serverside and check if clients points to DNS server.

Regards
0
 

Author Comment

by:osea
ID: 19589243
Hi MrHusy,

This is not seem like a DNS issue. This network has a simple design, at this site a single DC running DNS.
There are no errors in DNS logs. DNS does not seems like a good candidate, I
will recheck but given the simplicity of the design it seems unlikely.

A second reboot and logon during the day executes quickly, usually 30-90
seconds. A logout and logon executes 10-40 seconds.

Any other suggestions?

Any suggestions on how timeout/hangs of profile or Group Policy processing can be identified during reboot and logon, other then UserEnv.log?
0
 
LVL 25

Expert Comment

by:Ron Malmstead
ID: 19592719
osea,

Read here first.
http://technet2.microsoft.com/windowsserver/en/library/89d7ec5f-a909-4f61-aded-c5b69f5f730b1033.mspx?mfr=true

It would appear to me that under the syncronous logon, which is caused due to the fact that you have roaming user profiles,  is causing the delay.  Most likely you have a script that is in one your GPO's, and it is taking a long time to execute...or a there is a bad line of code in a batch file that is taking awhile to timeout...   The syncronous logon will basically  apply each gpo one at a time.  So if the first GPO has logon script that are moving slowly...the other GPO's will not apply until it is finished.  Without using roaming profiles this wouldn't be an issue, but with roaming profiles, the user will not be shown the desktop until all scripts and gpo's are executed and applied..

Option A: get rid of the roaming profiles...
Option B: find out which GPO is running slowly  or which script is timing out.....  Disable all GPO's or scripts... and re-enable them one at a time for testing purposes.

Here's an example ...  Let say you use a script to copy a shortcut from a network location.. to the user's desktop..  if your using roaming profiles... this could be a problem because the script will hang until the profile loads and the profile won't want to load unless the script is finished executing.  Now you see the dilema ?  In this case you would get better execution time by copying the shortcut to the %allusersprofile%\desktop, beause it is already local to the machine.
0
 

Author Comment

by:osea
ID: 19595365
Hi xuserx2000,

The most helpful post, many thanks. Roaming profiles are a requirement, so getting rid to them is not an option. But, I really want a solution for isolating the issue, so I don't consider this a viable solution.

Netdiag and Dcdiag are running without error, except for WINS error, which should not be an issue (except for login script). So DNS and AD replication appear fine, since no event log errors.

Potential issues for this scenario are:
1) Access control problems on Sysvol.
2) Anti-virus causing problems with the Sysvol.
3) If the gpupdate /force timeout and the first logon of the day issue are related, both process the  
     Security policy even if it has not been changed.
4) permission problem GPO in AD - but this should generate errors in UserEnv.log
5) Timeout in processing login script, profile, CSE
6) Corrupted/bad GPT cuasing slow processing - but no errors in UserEnvlog?

I discovered how the run RegMon during bootup. SysInternal Psexec can run Regmon in the local system account so that it captures a trace of your logon:

psexec s i d c:\sysint\regmon.exe

The delay being experienced has occurred without any obvious changes. There is a WINS error, so I will check NetBIOS names within scripts. I will certainly check script execution for timeout issues, but no changes have been introduced and login times have changed substantially.

The delay is in applying the computer policy, where there is one script. It takes nearly 7 minutes for the computer policy to apply on this test PC and 3 seconds to apply the user policy.

09:17:51:093 ApplyGroupPolicy
09:17:51:109 ProcessGPOs: Starting computer Group Policy
09:18:25:437 ProcessGPOs: User name is:
CN=TESTPC,OU=IT_GROUP,OU=DESKTOPS,OU=RESOURCES
09:24:48:877 ProcessGPOs: Leaving with 1

09:24:53:226 ApplyGroupPolicy
09:24:53:336 ProcessGPOs: User name is: CN=TESTUSER,OU= IT_GROUP
09:24:53:711 SearchDSObject: Searching OU= IT_GROUP
09:24:56:606 ProcessGPOs: Leaving with 1

Osea
0
 
LVL 1

Accepted Solution

by:
Computer101 earned 0 total points
ID: 21888911
PAQed with points refunded (500)

Computer101
EE Admin
0

Featured Post

How to Use the Help Bell

Need to boost the visibility of your question for solutions? Use the Experts Exchange Help Bell to confirm priority levels and contact subject-matter experts for question attention.  Check out this how-to article for more information.

Question has a verified solution.

If you are experiencing a similar issue, please ask a related question

Let's recap what we learned from yesterday's Skyport Systems webinar.
Transferring FSMO roles is done when an admin wants to split roles between certain Domain Controllers or the Domain Controller holding the Roles has been forcefully demoted using dcpromo / forceremoval
Are you ready to implement Active Directory best practices without reading 300+ pages? You're in luck. In this webinar hosted by Skyport Systems, you gain insight into Microsoft's latest comprehensive guide, with tips on the best and easiest way…
There are cases when e.g. an IT administrator wants to have full access and view into selected mailboxes on Exchange server, directly from his own email account in Outlook or Outlook Web Access. This proves useful when for example administrator want…

862 members asked questions and received personalized solutions in the past 7 days.

Join the community of 500,000 technology professionals and ask your questions.

Join & Ask a Question