[gptalk] Re: Small login delay

  • From: Steven <usersend@xxxxxxxxx>
  • To: gptalk@xxxxxxxxxxxxx
  • Date: Thu, 3 May 2007 17:09:44 -0400

At first glance, it seems that your problem might lay in a change in
security seeing the impersonation failures but there is a lot of information
still needed to diagnose this. First, what kind of login scripts do you have
running (VBS, Kickstart ect.) ? Anything trying to start a 16 bit app? How
are the scripts being applied? Are you applying and reg changes in the logon
process?

Simply speaking, the process of the actual logon from XP to say Windows 2003
server is very quick and mostly deals with the Kerberos authentication
sequence. if this was failing you would not be logged on or you would get a
cached logon message in your logs. So, chances are is is not the actualy
authentication process.

That being said, First, look at your GPO's (Run gpresult in verbose mode on
the client after logon finaly happens and pay special attention to the
details). Just to be able to rule them out, turn your GPO's off and test
logon ith each additional being turned on.
Second, I would look at the profiles. Does the problem exist for any account
being logged on? When you log on with local admin, does the problem seem to
go away? If it does that narrows it a bit more.

like I said, there needs to be a lot more info on this. Windows XP relies on
DNS to initiate the logon process, is DNS functioning correctly? Are your
sites functioning? Is the client logging onto the correct DC (Run SET
command)?

Those are the places I would start with





On 5/3/07, Difarnecio, Gino (Citco) <GDifarnecio@xxxxxxxxx> wrote:

 I am not certain that this problem is policy related. Seeing as we have
some policy based scripts, I thought it might be linked.

We are experiencing some small login delays on all of our systems. It
seems that if we disable all of the non-microsoft services we can get a
login down to about 15-20 seconds. Meaning, this is how long it takes for
the desktop to be presented.  However, upon enabling all of the non-windows
, yet equally necessary services, we have login delays running over 1.5minutes.

I've enabled the Userenv logging and am able to determine that the delay
takes place at the computer and not the user level. It seems that the
delay is caused at the profile loading part of the process. The exact
process causing the delay is CMD.exe. Unfortunately, I am not sure what
triggers the call to this process. I have tried disabling each of the
process, one by one to try and narrow it down. It seems that enabling a
single process, doesn 't matter which one, will introduce this delay and
the call to cmd.exe.

We have some polices that contain login scripts, but none of these should
really come into play until the user logins. I have atta ched the relevant
section of the Userenv.log file.

Any help or guidance with this issue would be immensely appreciated.

USERENV(598.59c) 10:31:37:312 LoadUserProfile: Entering, hToken = <0x96c>,
lpProfileInfo = 0x6e3e0

USERENV(598.59c) 10:31:37:312 LoadUserProfile: lpProfileInfo->dwFlags =
<0x0>

USERENV(598.59c) 10:31:37:312 LoadUserProfile: lpProfileInfo->lpUserName =
<gdifcio>

USERENV(598.59c) 10:31:37:312 LoadUserProfile: NULL central profile path

USERENV(598.59c) 10:31:37:312 LoadUserProfile:
lpProfileInfo->lpDefaultPath = <\\ADDC27\netlogon\Default User>

USERENV(598.59c) 10:31:37:312 LoadUserProfile: NULL server name

USERENV(598.59c) 10:31:37:312 LoadUserProfile: User sid:
S-1-5-21-3061726268-1491933618-2623018998-10550

USERENV(598.59c) 10:31:37:312 CSyncManager::EnterLock
<S-1-5-21-3061726268-1491933618-2623018998-10550>

USERENV(598.59c) 10:31:37:312 CSyncManager::EnterLock: No existing entry
found

USERENV(598.59c) 10:31:37:312 CSyncManager::EnterLock: New entry created

USERENV(598.59c) 10:31:37:312 CHashTable::HashAdd:
S-1-5-21-3061726268-1491933618-2623018998-10550 added in bucket 9

USERENV(598.59c) 10:31:37:312 LoadUserProfile: Wait succeeded. In critical
section.

USERENV(598.59c) 10:31:37:312 RestoreUserProfile:  Entering

USERENV(598.59c) 10:31:37:312 RestoreUserProfile:  User is a Admin

USERENV(598.59c) 10:31:37:312 IsCentralProfileReachable:  Entering

USERENV(598.59c) 10:31:37:312 IsCentralProfileReachable:  Null path.
Leaving

USERENV(598.59c) 10:31:37:312 RestoreUserProfile:  Profile path = <>

USERENV(598.59c) 10:31:37:312 ExtractProfileFromBackup:  A profile already
exists

USERENV(598.59c) 10:31:37:312 PatchNewProfileIfRequred: A profile already
exists with the current sid, exitting

USERENV(598.59c) 10:31:37:312 CreateLocalProfileKey:  Not setting
additional Security

USERENV(598.59c) 10:31:37:312 GetExistingLocalProfileImage:  Found entry
in profile list for existing local profile

USERENV(598.59c) 10:31:37:312 GetExistingLocalProfileImage:  Local profile
image filename = <%SystemDrive%\Documents and Settings\gdifcio>

USERENV(598.59c) 10:31:37:312 GetExistingLocalProfileImage:  Expanded
local profile image filename = <C:\Documents and Settings\gdifcio>

USERENV(598.59c) 10:31:37:421 GetExistingLocalProfileImage:  No local
mandatory profile.  Error = 2

USERENV(598.59c) 10:31:37:515 GetExistingLocalProfileImage:  Found local
profile image file ok <C:\Documents and Settings\gdifcio\ntuser.dat>

USERENV(598.59c) 10:31:37:765 GetExistingLocalProfileImage:  Failed to
query low profile unload time with error 2

USERENV(598.59c) 10:31:37:796 Local Existing Profile Image is reachable

USERENV(598.59c) 10:31:37:796 Local profile name is <C:\Documents and
Settings\gdifcio>

USERENV(598.59c) 10:31:37:796 RestoreUserProfile:  No central profile.
Attempting to load local profile.

USERENV(598.59c) 10:31:38:500 MyRegLoadKey: Returning 00000000

USERENV(598.59c) 10:31:39:468 MyRegLoadKey: Returning 00000000

USERENV(598.59c) 10:31:39:468 CreateClassHive: existing user classes hive
found

USERENV(598.59c) 10:31:39:468 RestoreUserProfile:  About to Leave.  Final
Information follows:

USERENV(598.59c) 10:31:39:468 Profile was successfully loaded.

USERENV(598.59c) 10:31:39:468 lpProfile->lpRoamingProfile = <>

USERENV(598.59c) 10:31:39:468 lpProfile->lpLocalProfile = <C:\Documents
and Settings\gdifcio>

USERENV(598.59c) 10:31:39:468 lpProfile->dwInternalFlags = 0x100

USERENV(598.59c) 10:31:39:468 RestoreUserProfile:  Leaving.

USERENV(598.59c) 10:31:39:468 UpgradeProfile: Entering

USERENV(598.59c) 10:31:39:468 UpgradeProfile: Build numbers match

USERENV(598.59c) 10:31:39:468 UpgradeProfile: Leaving Successfully

USERENV(598.59c) 10:31:39:468 Profile Ref Count is 1

USERENV(598.59c) 10:31:39:468 LoadUserProfile: Leaving critical Section.

USERENV(598.59c) 10:31:39:468 CSyncManager::LeaveLock
<S-1-5-21-3061726268-1491933618-2623018998-10550>

USERENV(598.59c) 10:31:39:468 CSyncManager::LeaveLock: Lock released

USERENV(598.59c) 10:31:39:468 CHashTable::HashDelete:
S-1-5-21-3061726268-1491933618-2623018998-10550 deleted

USERENV(598.59c) 10:31:39:468 CSyncManager::LeaveLock: Lock deleted

USERENV(598.59c) 10:31:39:468 LoadUserProfile: Impersonated user:
0000096c, 00000000

USERENV(5d0.620) 10:31:39:750 ImpersonateUser: Failed to impersonate user
with 5.

USERENV(5d0.620) 10:31:39:765 GetUserNameAndDomain Failed to impersonate
user

USERENV(5d0.620) 10:31:39:781 ImpersonateUser: Failed to impersonate user
with 5.

USERENV(5d0.620) 10:31:39:781 GetUserDNSDomainName: Failed to impersonate
user

USERENV(5d0.620) 10:31:40:218 ImpersonateUser: Failed to impersonate user
with 5.

USERENV(5d0.620) 10:31:40:218 GetUserNameAndDomain Failed to impersonate
user

USERENV(5d0.620) 10:31:40:218 ImpersonateUser: Failed to impersonate user
with 5.

USERENV(5d0.620) 10:31:40:218 GetUserDNSDomainName: Failed to impersonate
user

USERENV(5d0.620) 10:31:40:468 ImpersonateUser: Failed to impersonate user
with 5.

USERENV(5d0.620) 10:31:40:468 GetUserNameAndDomain Failed to impersonate
user

USERENV(5d0.620) 10:31:40:468 ImpersonateUser: Failed to impersonate user
with 5.

USERENV(5d0.620) 10:31:40:468 GetUserDNSDomainName: Failed to impersonate
user

USERENV(598.59c) 10:31:40:468 LoadUserProfile: Reverted to user: 00000000

USERENV(598.59c) 10:31:40:468 LoadUserProfile: Leaving with a value of 1.

USERENV(598.59c) 10:31:40:468
=========================================================

USERENV(598.59c) 10:31:40:468 LoadUserProfile: LoadUserProfileP succeeded

USERENV(598.59c) 10:31:40:468 LoadUserProfile:  Returning success.  Final
Information follows:

USERENV(598.59c) 10:31:40:468 lpProfileInfo->UserName = <gdifarnecio>

USERENV(598.59c) 10:31:40:468 lpProfileInfo->lpProfilePath = <>

USERENV(598.59c) 10:31:40:468 lpProfileInfo->dwFlags = 0x0

USERENV(598.59c) 10:31:40:468 LoadUserProfile: Returning TRUE. hProfile =
<0x98c>

USERENV(4c8.1b8) 10:31:42:953 LibMain: Process Name:
C:\WINDOWS\system32\SearchIndexer.exe

USERENV(598.59c) 10:31:46:015 IsSyncForegroundPolicyRefresh: Synchronous,
Reason: NonCachedCredentials

USERENV(598.440) 10:31:46:015 IsSyncForegroundPolicyRefresh: Synchronous,
Reason: NonCachedCredentials

USERENV(7e0.7c) 10:31:52:500 LibMain: Process Name:
C:\WINDOWS\system32\cmd.exe

USERENV(598.a0) 10:32:40:549 ProcessGPOs: network name is local





 Disclaimer link. To see it, just click the link below, or copy and
paste it into your browser's address line.
http://www.citco.com/emaildisclaimer.htm




--
Steve

Other related posts: