Re: (Trying to debug) Laptop Latency issues off of domain network



Ok, I've gathered a lot of input (Thanks, not done yet though ). I'm going to
carry out some more tests; I'll post the results as i get them. In brief i
will focus on looking at GPOs and their effects on this problem (i believe we
all gather that may be the source of the problem). Simaltaneuously i would
appreciate anyone's inputs on the following two UsrEnv event entries that (1)
occur consistently and (2) are a massive percentage of the delay in any given
login session (remember: when logging in off the domain). Again, i highlight
the entries between which the delay is logged (in red) & enclose/include some
surrounding entries that occur similarly per login (to give us a better idea
of excactly what is going on).

Case 1: "AbleToBypassCSC: tried NPAddConnection3ForCSCAgent. Error 53"

-->> USERENV(3a4.3a8) 07:45:19:734 AbleToBypassCSC: tried
NPAddConnection3ForCSCAgent. Error 53
-->> USERENV(3a4.3a8) 07:45:40:828 UnLoadUserProfileP: CSC bypassed failed.
Ignoring Roaming profile path
USERENV(3a4.3a8) 07:45:40:828 GetExclusionListFromRegistry: Policy list is
empty, returning user list = <Local Settings;Temporary Internet
Files;History;Temp;Local Settings\Application Data\Microsoft\Outlook>
USERENV(3a4.3a8) 07:45:40:828 CSyncManager::EnterLock
<S-1-5-21-1687723350-4253359750-3876547176-1152>
USERENV(3a4.3a8) 07:45:40:828 CSyncManager::EnterLock: No existing entry found
USERENV(3a4.3a8) 07:45:40:843 CSyncManager::EnterLock: New entry created
USERENV(3a4.3a8) 07:45:40:843 CHashTable::HashAdd:
S-1-5-21-1687723350-4253359750-3876547176-1152 added in bucket 10
USERENV(3a4.3a8) 07:45:40:843 UnloadUserProfileP: Wait succeeded. In
critical section.
USERENV(3a4.3a8) 07:45:40:843 MyRegUnLoadKey: Failed to unmount hive 00000005
USERENV(3a4.3a8) 07:45:40:843 MyRegUnLoadKey: Returning 0.
USERENV(3a4.3a8) 07:45:40:843 DumpOpenRegistryHandle: 4 user registry
Handles leaked from
\Registry\User\S-1-5-21-1687723350-4253359750-3876547176-1152
USERENV(3a4.3a8) 07:45:40:843 UnloadUserProfileP: Didn't unload user profile
<err = 5>
USERENV(3a4.3a8) 07:45:40:859 MyRegUnLoadKey: Returning 1.
USERENV(3a4.3a8) 07:45:40:859 UnLoadClassHive: Successfully unmounted
S-1-5-21-1687723350-4253359750-3876547176-1152_Classes
USERENV(3a4.3a8) 07:45:40:859 UnloadUserProfileP: Successfully unloaded user
classes
USERENV(3a4.3a8) 07:45:40:859 HandleRegKeyLeak: RtlAdjustPrivilege succeeded!
USERENV(3a4.3a8) 07:45:41:546 HandleRegKeyLeak: RegSaveKey succeeded!
USERENV(3a4.3a8) 07:45:41:562 HandleRegKeyLeak: RtlAdjustPrivilege succeeded!
USERENV(3a4.3a8) 07:45:41:562 HandleRegKeyLeak: hkCurrentUser closed
USERENV(3a4.3a8) 07:45:41:562 Entering CUserProfile::WatchHiveRefCount:
S-1-5-21-1687723350-4253359750-3876547176-1152, 1
USERENV(3a4.3a8) 07:45:41:562 CUserProfile::WatchHiveRefCount: In critical
section
USERENV(3a4.3a8) 07:45:41:562 CUserProfile::WatchHiveRefCount: NtUnloadKeyEx
succeeded for \Registry\User\S-1-5-21-1687723350-4253359750-3876547176-1152
USERENV(3a4.3a8) 07:45:41:562 Entering CUserProfile::AddWorkItem:
S-1-5-21-1687723350-4253359750-3876547176-1152
USERENV(3a4.3a8) 07:45:41:562 CHashTable::HashAdd:
S-1-5-21-1687723350-4253359750-3876547176-1152 added in bucket 10
USERENV(3a4.3a8) 07:45:41:562 CUserProfile::AddWorkItem: No thread
available, create a new one.
USERENV(3a4.3a8) 07:45:41:562 CUserProfile::AddWorkItem: Signal event item
inserted

This first example occurs right at the beginning of the login, in logins
where network connectivity is available when not on the domain. Delays are
~21sec (most of the time) == ~7% of total login time in some cases. I can't
find anything useful on this event anywhere (!). I'm sure *someone* out there
must know something about what this means. ANY INFORMATION WOULD BE
APPRECIATED!


Case 2: "LibMain: Process Name: C:\WINDOWS\system32\wbem\wmiprvse.exe"

USERENV(3a8.4c8) 12:23:12:734 LoadUserProfileI: returning 0
USERENV(3d4.2b0) 12:23:12:734 LoadUserProfile: Running as self
USERENV(3d4.2b0) 12:23:12:734 LoadUserProfile: Calling LoadUserProfileI (as
user) succeeded
USERENV(3d4.2b0) 12:23:12:734 LoadUserProfile: Returning success. Final
Information follows:
USERENV(3d4.2b0) 12:23:12:734 lpProfileInfo->UserName = <LocalService>
USERENV(3d4.2b0) 12:23:12:750 lpProfileInfo->lpProfilePath = <>
USERENV(3d4.2b0) 12:23:12:750 lpProfileInfo->dwFlags = 0x9
USERENV(3a8.3c0) 12:23:12:750 IProfileSecurityCallBack: client authenticated.
USERENV(3a8.3c0) 12:23:12:750 ReleaseClientContext: Releasing context
USERENV(3a8.3c0) 12:23:12:750 ReleaseClientContext_s: Releasing context
USERENV(3a8.3c0) 12:23:12:750 MIDL_user_free enter
USERENV(3d4.2b0) 12:23:12:750 ReleaseInterface: Releasing rpc binding handle
USERENV(3d4.2b0) 12:23:12:750 LoadUserProfile: Returning TRUE. hProfile =
<0x3bc>
USERENV(3d4.2b0) 12:23:12:750 GetUserDNSDomainName: Domain name is NT
Authority. No DNS domain name available.
USERENV(1e4.1d8) 12:23:12:875 LibMain: Process Name:
C:\WINDOWS\System32\alg.exe
USERENV(160.1e0) 12:23:13:031 LibMain: Process Name:
C:\WINDOWS\system32\wuauclt.exe
USERENV(324.328) 12:23:13:546 LibMain: Process Name:
C:\WINDOWS\system32\ctfmon.exe
USERENV(604.408) 12:23:14:234 LibMain: Process Name: C:\Program
Files\HPQ\IAM\bin\asghost.exe
-->> USERENV(654.220) 12:23:15:625 LibMain: Process Name:
C:\WINDOWS\system32\wbem\wmiprvse.exe
-->> USERENV(3a8.56c) 12:24:15:281 MyGetUserName: GetUserNameEx failed with
1722.
USERENV(3a8.56c) 12:24:15:281 MyGetUserName: Retrying call to GetUserNameEx
in 1/2 second.
USERENV(a40.a44) 12:24:28:734 LibMain: Process Name:
C:\WINDOWS\system32\userinit.exe
USERENV(3e0.3f4) 12:24:28:875 ImpersonateUser: Failed to impersonate user
with 5.
USERENV(3e0.3f4) 12:24:28:875 GetUserNameAndDomain Failed to impersonate user
USERENV(3e0.3f4) 12:24:28:875 ImpersonateUser: Failed to impersonate user
with 5.
USERENV(3e0.3f4) 12:24:28:875 GetUserDNSDomainName: Failed to impersonate user
USERENV(3e0.3f4) 12:24:28:906 ImpersonateUser: Failed to impersonate user
with 5.
USERENV(3e0.3f4) 12:24:28:906 GetUserNameAndDomain Failed to impersonate user
USERENV(3e0.3f4) 12:24:28:906 ImpersonateUser: Failed to impersonate user
with 5.
USERENV(3e0.3f4) 12:24:28:906 GetUserDNSDomainName: Failed to impersonate user
USERENV(3e0.3f4) 12:24:28:921 ImpersonateUser: Failed to impersonate user
with 5.
USERENV(3e0.3f4) 12:24:28:937 GetUserNameAndDomain Failed to impersonate user
USERENV(3e0.3f4) 12:24:28:937 ImpersonateUser: Failed to impersonate user
with 5.
USERENV(3e0.3f4) 12:24:28:937 GetUserDNSDomainName: Failed to impersonate user
USERENV(a58.a5c) 12:24:29:765 LibMain: Process Name: C:\WINDOWS\Explorer.EXE
USERENV(a58.a70) 12:24:29:859 GetProfileType: Profile already loaded.
USERENV(a58.a70) 12:24:29:859 GetProfileType: ProfileFlags is 0
USERENV(a58.a70) 12:24:29:875 GetProfileType: Profile already loaded.
USERENV(a58.a70) 12:24:29:890 GetProfileType: ProfileFlags is 0
USERENV(adc.ae0) 12:24:34:984 LibMain: Process Name: C:\Program Files\Common
Files\Symantec Shared\ccApp.exe

This second example occurs like thus almost everytime. The highlighted event
concerns the Windows Management Instrumentation (WMI). Delays are ~45secs to
~1min == 10% - 30% of total login time! What i don't understand is that: (1)
When logging on the domain/corporate-network the delays between this and the
next even are minimal versus when logging onto a non-domain network it is
(one of the most) massive; (2) I would say the delay itself can't have
anything to do with the WMI app but log entries show the delay occuring
always after that event; and (3) I observe that the event always occurs thus
on logons in NON-DOMAIN networks:

USERENV(654.220) 12:23:15:625 LibMain: Process Name:
C:\WINDOWS\system32\wbem\wmiprvse.exe
USERENV(3a8.56c) 12:24:15:281 MyGetUserName: GetUserNameEx failed with 1722.

(and that's when it takes the most amount of time), i.e. with the
"MyGetUserName: GetUserNameEx failed with 1722" event. I can't find any
documentation on this. Why does this occur when logging in off the domain can
be answered intuitively but i feel like understanding this in more detail
would help us understand ( a ) the reason for the massive delay more
technically ( b ) how to turn it off - or give us a good idea if we just need
to change the way we do things completely.

Does anyone have any idea why this event takes so long? Can we shut this
off? (i don't think i clearly understand the need for WMI either)

Thanks
.



Relevant Pages

  • Re: limit the maximum time allowed for a log-in attempt
    ... to create a delay between each consecutive login attempt ... >> is some delay between consecutive windows logon attempt. ... >long an account is locked out for; ... >lockout threshold figure. ...
    (microsoft.public.security)
  • Delay in logging in
    ... Logging in is very slow. ... Running 'su' from a shell gives the same delay as ... then about ten screens of output dumped to the screen. ...
    (alt.os.linux.suse)
  • Re: [SLE] Login delay
    ... Logging in prompts for a password. ... It doesn't matter where or how I'm logging in. ... >> which requires the root password, gives the same delay. ... > similar network problems. ...
    (SuSE)
  • Re: [SLE] Login delay
    ... Logging in prompts for a password. ... It doesn't matter where or how I'm logging in. ... > which requires the root password, gives the same delay. ... similar network problems. ...
    (SuSE)
  • Re: Erratic slow login Win2k3 from XP SP2 - Profile GPO issue log usel
    ... Delay with irratic presence and DNS sort of come in same breath. ... Policy engine could be doing all right and at max efficiency given ... user profile. ... This appears to be slowest for the first login during the ...
    (microsoft.public.windows.group_policy)