none
Takes up to 5 min "Applying User Settings" with events ID 6005 6006 after a reboot - Win Server 2008 R2 Standard 64bit

    Question

  • Hi,

    Has anybody seen the issue below showing in the logs? The time for the logs messages switch from the real time (17:57) to some random time (10:55). There seem to be a disconnect with the time. I noticed right when the status message while logging in switches to "apply user settings", the time get screwed up on the gpsvc.log file and switches to the random time (10:55) and keeps reporting that random time till "apply user settings" process completes and switches back to regular real time (17:57). I made sure the server is synced up with w32tm /resync command. Tried different DNS settings. Tried dis joining and rejoining to the domain. tried to block inheritance on GPMC to that OU. Created new domain user. Deleted local profiles. All with no luck and same behavior which is taking up to 5 min "applying user setting" only after a reboot. If I log in and out without reboot, it would log in just fine within seconds.

    Any thoughts or suggestions are appreciated!

    Thanks,

    Here is a copy from the gpsvc.log:

    GPSVC(338.354) 17:57:08:406 -------------------------------------------
    GPSVC(338.354) 17:57:08:406 Use the Event Viewer to analyze the Group Policy operational log for details on Group Policy service activity.
    GPSVC(338.354) 17:57:08:406 -------------------------------------------
    GPSVC(338.354) 17:57:08:406  
    GPSVC(338.354) 17:57:08:406 InitializeProductType: Product Type: 2
    GPSVC(338.354) 17:57:08:406 Register for connectivity notification is Enabled.
    GPSVC(338.354) 17:57:08:406 Connectivity manager class initialized with for IntranetAuth connectivity
    GPSVC(338.354) 17:57:08:640 Target = Machine
    GPSVC(338.350) 17:57:08:640 Target = Machine, ChangeNumber 0
    GPSVC(338.39c) 17:57:09:232 bMachine = 1 
    GPSVC(338.39c) 17:57:09:232 Setting GPsession state = 1
    GPSVC(338.27c) 17:57:09:232 Waiting for connectivity before applying policies
    GPSVC(338.27c) 17:57:09:232 Waiting for SamSs with timeout 8264
    GPSVC(338.39c) 17:57:09:232 Message Status = <Applying computer settings...>
    GPSVC(338.39c) 17:57:09:232 Target = Machine
    GPSVC(338.39c) 17:57:09:232 Target = Machine, ChangeNumber 0
    GPSVC(338.39c) 17:57:09:248 Setting GPsession state = 1
    GPSVC(338.27c) 17:57:09:357 Waiting for NTDS.IndexRecreateEvent with timeout 8139
    GPSVC(338.27c) 17:57:09:357 Waiting for NlaSvc with timeout 8139
    GPSVC(338.350) 17:57:09:576 Sid = (null), dwTimeout = 1, dwFlags = 268435459
    GPSVC(338.350) 17:57:09:576 LockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:576 Async Lock called
    GPSVC(338.350) 17:57:09:576 Reader Lock got immediately. m_cReadersInLock : 1
    GPSVC(338.350) 17:57:09:576 Sid = (null), dwTimeout = 1, dwFlags = 268435459
    GPSVC(338.350) 17:57:09:576 LockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:576 Async Lock called
    GPSVC(338.350) 17:57:09:576 Reader Lock got immediately. m_cReadersInLock : 2
    GPSVC(338.350) 17:57:09:576 Sid = (null)
    GPSVC(338.350) 17:57:09:576 UnLockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:576 Found the caller in the ReaderHavingLock List. Removing it...
    GPSVC(338.350) 17:57:09:576 UnLocked successfully
    GPSVC(338.350) 17:57:09:576 Sid = (null), dwTimeout = 1, dwFlags = 268435459
    GPSVC(338.350) 17:57:09:576 LockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:576 Async Lock called
    GPSVC(338.350) 17:57:09:576 Reader Lock got immediately. m_cReadersInLock : 2
    GPSVC(338.350) 17:57:09:576 Sid = (null)
    GPSVC(338.350) 17:57:09:576 UnLockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:576 Found the caller in the ReaderHavingLock List. Removing it...
    GPSVC(338.350) 17:57:09:576 UnLocked successfully
    GPSVC(338.350) 17:57:09:576 Sid = (null), dwTimeout = 1, dwFlags = 268435459
    GPSVC(338.350) 17:57:09:576 LockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:576 Async Lock called
    GPSVC(338.350) 17:57:09:576 Reader Lock got immediately. m_cReadersInLock : 2
    GPSVC(338.350) 17:57:09:576 Sid = (null)
    GPSVC(338.350) 17:57:09:576 UnLockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:576 Found the caller in the ReaderHavingLock List. Removing it...
    GPSVC(338.350) 17:57:09:576 UnLocked successfully
    GPSVC(338.350) 17:57:09:576 Sid = (null), dwTimeout = 1, dwFlags = 268435459
    GPSVC(338.350) 17:57:09:576 LockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:576 Async Lock called
    GPSVC(338.350) 17:57:09:576 Reader Lock got immediately. m_cReadersInLock : 2
    GPSVC(338.350) 17:57:09:576 Sid = (null)
    GPSVC(338.350) 17:57:09:576 UnLockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:576 Found the caller in the ReaderHavingLock List. Removing it...
    GPSVC(338.350) 17:57:09:576 UnLocked successfully
    GPSVC(338.350) 17:57:09:576 Sid = (null), dwTimeout = 1, dwFlags = 268435459
    GPSVC(338.350) 17:57:09:576 LockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:576 Async Lock called
    GPSVC(338.350) 17:57:09:576 Reader Lock got immediately. m_cReadersInLock : 2
    GPSVC(338.350) 17:57:09:576 Sid = (null)
    GPSVC(338.350) 17:57:09:576 UnLockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:576 Found the caller in the ReaderHavingLock List. Removing it...
    GPSVC(338.350) 17:57:09:576 UnLocked successfully
    GPSVC(338.350) 17:57:09:576 Sid = (null), dwTimeout = 1, dwFlags = 268435459
    GPSVC(338.350) 17:57:09:576 LockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:576 Async Lock called
    GPSVC(338.350) 17:57:09:576 Reader Lock got immediately. m_cReadersInLock : 2
    GPSVC(338.350) 17:57:09:576 Sid = (null)
    GPSVC(338.350) 17:57:09:576 UnLockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:576 Found the caller in the ReaderHavingLock List. Removing it...
    GPSVC(338.350) 17:57:09:576 UnLocked successfully
    GPSVC(338.350) 17:57:09:576 Sid = (null), dwTimeout = 1, dwFlags = 268435459
    GPSVC(338.350) 17:57:09:576 LockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:576 Async Lock called
    GPSVC(338.350) 17:57:09:576 Reader Lock got immediately. m_cReadersInLock : 2
    GPSVC(338.350) 17:57:09:576 Sid = (null)
    GPSVC(338.350) 17:57:09:576 UnLockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:576 Found the caller in the ReaderHavingLock List. Removing it...
    GPSVC(338.350) 17:57:09:576 UnLocked successfully
    GPSVC(338.350) 17:57:09:576 Sid = (null), dwTimeout = 1, dwFlags = 268435459
    GPSVC(338.350) 17:57:09:576 LockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:576 Async Lock called
    GPSVC(338.350) 17:57:09:576 Reader Lock got immediately. m_cReadersInLock : 2
    GPSVC(338.350) 17:57:09:576 Sid = (null)
    GPSVC(338.350) 17:57:09:576 UnLockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:576 Found the caller in the ReaderHavingLock List. Removing it...
    GPSVC(338.350) 17:57:09:576 UnLocked successfully
    GPSVC(338.350) 17:57:09:576 Sid = (null), dwTimeout = 1, dwFlags = 268435459
    GPSVC(338.350) 17:57:09:576 LockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:576 Async Lock called
    GPSVC(338.350) 17:57:09:576 Reader Lock got immediately. m_cReadersInLock : 2
    GPSVC(338.350) 17:57:09:576 Sid = (null)
    GPSVC(338.350) 17:57:09:576 UnLockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:576 Found the caller in the ReaderHavingLock List. Removing it...
    GPSVC(338.350) 17:57:09:576 UnLocked successfully
    GPSVC(338.350) 17:57:09:576 Sid = (null), dwTimeout = 1, dwFlags = 268435459
    GPSVC(338.350) 17:57:09:576 LockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:576 Async Lock called
    GPSVC(338.350) 17:57:09:576 Reader Lock got immediately. m_cReadersInLock : 2
    GPSVC(338.350) 17:57:09:576 Sid = (null)
    GPSVC(338.350) 17:57:09:576 UnLockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:576 Found the caller in the ReaderHavingLock List. Removing it...
    GPSVC(338.350) 17:57:09:576 UnLocked successfully
    GPSVC(338.350) 17:57:09:576 Sid = (null), dwTimeout = 1, dwFlags = 268435459
    GPSVC(338.350) 17:57:09:576 LockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:576 Async Lock called
    GPSVC(338.350) 17:57:09:576 Reader Lock got immediately. m_cReadersInLock : 2
    GPSVC(338.350) 17:57:09:576 Sid = (null)
    GPSVC(338.350) 17:57:09:576 UnLockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:576 Found the caller in the ReaderHavingLock List. Removing it...
    GPSVC(338.350) 17:57:09:576 UnLocked successfully
    GPSVC(338.350) 17:57:09:576 Sid = (null), dwTimeout = 1, dwFlags = 268435459
    GPSVC(338.350) 17:57:09:576 LockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:576 Async Lock called
    GPSVC(338.350) 17:57:09:576 Reader Lock got immediately. m_cReadersInLock : 2
    GPSVC(338.350) 17:57:09:576 Sid = (null)
    GPSVC(338.350) 17:57:09:576 UnLockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:576 Found the caller in the ReaderHavingLock List. Removing it...
    GPSVC(338.350) 17:57:09:576 UnLocked successfully
    GPSVC(338.350) 17:57:09:576 Sid = (null), dwTimeout = 1, dwFlags = 268435459
    GPSVC(338.350) 17:57:09:576 LockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:576 Async Lock called
    GPSVC(338.350) 17:57:09:576 Reader Lock got immediately. m_cReadersInLock : 2
    GPSVC(338.350) 17:57:09:576 Sid = (null)
    GPSVC(338.350) 17:57:09:576 UnLockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:591 Found the caller in the ReaderHavingLock List. Removing it...
    GPSVC(338.350) 17:57:09:591 UnLocked successfully
    GPSVC(338.350) 17:57:09:591 Sid = (null), dwTimeout = 1, dwFlags = 268435459
    GPSVC(338.350) 17:57:09:591 LockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:591 Async Lock called
    GPSVC(338.350) 17:57:09:591 Reader Lock got immediately. m_cReadersInLock : 2
    GPSVC(338.350) 17:57:09:591 Sid = (null)
    GPSVC(338.350) 17:57:09:591 UnLockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:591 Found the caller in the ReaderHavingLock List. Removing it...
    GPSVC(338.350) 17:57:09:591 UnLocked successfully
    GPSVC(338.350) 17:57:09:591 Sid = (null), dwTimeout = 1, dwFlags = 268435459
    GPSVC(338.350) 17:57:09:591 LockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:591 Async Lock called
    GPSVC(338.350) 17:57:09:591 Reader Lock got immediately. m_cReadersInLock : 2
    GPSVC(338.350) 17:57:09:591 Sid = (null)
    GPSVC(338.350) 17:57:09:591 UnLockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:591 Found the caller in the ReaderHavingLock List. Removing it...
    GPSVC(338.350) 17:57:09:591 UnLocked successfully
    GPSVC(338.350) 17:57:09:591 Sid = (null), dwTimeout = 1, dwFlags = 268435459
    GPSVC(338.350) 17:57:09:591 LockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:591 Async Lock called
    GPSVC(338.350) 17:57:09:591 Reader Lock got immediately. m_cReadersInLock : 2
    GPSVC(338.350) 17:57:09:591 Sid = (null)
    GPSVC(338.350) 17:57:09:591 UnLockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:591 Found the caller in the ReaderHavingLock List. Removing it...
    GPSVC(338.350) 17:57:09:591 UnLocked successfully
    GPSVC(338.350) 17:57:09:591 Sid = (null), dwTimeout = 1, dwFlags = 268435459
    GPSVC(338.350) 17:57:09:591 LockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:591 Async Lock called
    GPSVC(338.350) 17:57:09:591 Reader Lock got immediately. m_cReadersInLock : 2
    GPSVC(338.350) 17:57:09:591 Sid = (null)
    GPSVC(338.350) 17:57:09:591 UnLockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:591 Found the caller in the ReaderHavingLock List. Removing it...
    GPSVC(338.350) 17:57:09:591 UnLocked successfully
    GPSVC(338.350) 17:57:09:669 Sid = (null)
    GPSVC(338.350) 17:57:09:669 UnLockPolicySection called for user <Machine>
    GPSVC(338.350) 17:57:09:669 Found the caller in the ReaderHavingLock List. Removing it...
    GPSVC(338.350) 17:57:09:669 Setting lock state as notLocked
    GPSVC(338.350) 17:57:09:669 UnLocked successfully
    GPSVC(338.27c) 10:55:29:426 Waiting for NETLOGON with timeout 6392
    GPSVC(338.27c) 10:55:29:426 Waiting for MUP with timeout 6392
    GPSVC(338.27c) 10:55:29:426 Waiting for wkssvc to signal MUP event
    GPSVC(338.5bc) 10:55:29:519 Target = Machine
    GPSVC(338.5bc) 10:55:29:519 Target = Machine, ChangeNumber 0
    GPSVC(3b0.67c) 10:55:29:535 CGPNotify::RegisterForNotification: Entering with target Machine and event 0x16c
    GPSVC(3b0.67c) 10:55:29:535 Client_InitialRegisterForNotification: User = machine, changenumber = 0
    GPSVC(338.5bc) 10:55:29:535 Target = Machine
    GPSVC(3b0.67c) 10:55:29:535 Client_RegisterForNotification: User = machine, changenumber = 0
    GPSVC(3b0.67c) 10:55:29:535 CGPNotify::RegisterForNotification: Exiting with status = 0
    GPSVC(338.6c4) 10:55:29:535 Target = Machine
    GPSVC(338.5b0) 10:55:29:535 Target = Machine, ChangeNumber 0
    GPSVC(338.5b0) 10:55:29:535 Sid = (null), dwTimeout = 600000, dwFlags = 268435456
    GPSVC(338.5b0) 10:55:29:535 LockPolicySection called for user <Machine>
    GPSVC(338.5b0) 10:55:29:535 Async Lock called
    GPSVC(338.5b0) 10:55:29:535 Reader Lock got immediately. m_cReadersInLock : 1
    GPSVC(338.5bc) 10:55:29:535 Sid = (null)
    GPSVC(338.5bc) 10:55:29:535 UnLockPolicySection called for user <Machine>
    GPSVC(338.5bc) 10:55:29:535 Found the caller in the ReaderHavingLock List. Removing it...
    GPSVC(338.5bc) 10:55:29:535 Setting lock state as notLocked
    GPSVC(338.5bc) 10:55:29:535 UnLocked successfully
    GPSVC(338.754) 10:55:29:816 CGPNotify::RegisterForNotification: Entering with target Machine and event 0xc18
    GPSVC(338.754) 10:55:29:816 Client_InitialRegisterForNotification: User = machine, changenumber = 0
    GPSVC(338.350) 10:55:29:816 Target = Machine
    GPSVC(338.754) 10:55:29:816 Client_RegisterForNotification: User = machine, changenumber = 0
    GPSVC(338.754) 10:55:29:816 CGPNotify::RegisterForNotification: Exiting with status = 0
    GPSVC(338.27c) 10:55:29:987 Done waiting for MUP
    GPSVC(338.27c) 10:55:29:987 Waiting for DS with timeout 5830
    GPSVC(338.27c) 10:55:29:987 Registered for NLA notification successfully
    GPSVC(338.27c) 10:55:29:987 NlaGetIntranetCapability returned Not Ready error. Consider it as NOT intranet capable.
    GPSVC(338.27c) 10:55:29:987 There is no connectivity. Waiting for connectivity again...
    GPSVC(338.27c) 10:55:30:455 There is connectivity.
    GPSVC(338.27c) 10:55:30:455 We have network connectivity... proceeding to apply policy.
    GPSVC(338.27c) 10:55:30:455 NlaQueryNetSignatures returned 1 networks
    GPSVC(338.27c) 10:55:30:455 Found a intranet+auth network
    GPSVC(338.27c) 10:55:30:455 # of interfaces : 1
    GPSVC(338.27c) 10:55:30:455 Interface ID: {9538E3E7-197E-4A34-82B6-F457DC25D35D}
    GPSVC(338.27c) 10:55:30:455 Compartment ID: 1
    GPSVC(338.27c) 10:55:30:455 Setting the CompartmentId [1] on the current thread
    GPSVC(338.27c) 10:55:30:455 GetDomainControllerConnectionInfo: Enabling bandwidth estimate.
    GPSVC(338.27c) 10:55:30:502 Started bandwidth estimation successfully
    GPSVC(338.27c) 10:55:30:502 GetDomainControllerConnectionInfo: Getting Ldap Handles.
    GPSVC(338.27c) 10:55:30:502 GetLdapHandle:  Getting ldap handle for host: DC-MLIB.DOMAIN-NAME in domain: DOMAIN-NAME.
    GPSVC(338.27c) 10:55:30:502 GetLdapHandle:  Server connection established.
    GPSVC(338.27c) 10:55:30:502 GetLdapHandle:  Binding using only kerberos.
    GPSVC(338.27c) 10:55:30:518 GetLdapHandle:  Bound successfully.
    GPSVC(338.27c) 10:55:30:518 ReadGPExtensions: Rsop entry point not found for C:\Windows\System32\dskquota.dll.
    GPSVC(338.27c) 10:55:30:518 ReadGPExtensions: Rsop entry point not found for gptext.dll.
    GPSVC(338.27c) 10:55:30:518 ReadGPExtensions: Rsop entry point not found for C:\Windows\System32\iedkcs32.dll.
    GPSVC(338.27c) 10:55:30:518 ReadGPExtensions: Rsop entry point not found for C:\Windows\System32\iedkcs32.dll.
    GPSVC(338.27c) 10:55:30:518 ReadGPExtensions: Rsop entry point not found for gptext.dll.
    GPSVC(338.27c) 10:55:30:518 ReadGPExtensions: Rsop entry point not found for C:\Windows\System32\iedkcs32.dll.
    GPSVC(338.27c) 10:55:30:518 ReadGPExtensions: Rsop entry point not found for gptext.dll.
    GPSVC(338.27c) 10:55:30:518 ReadGPExtensions: Rsop entry point not found for gptext.dll.
    GPSVC(338.27c) 10:55:30:518 ProcessGPOs:  No site name defined.  Skipping site policy.
    GPSVC(338.27c) 10:55:30:518 GetGPOInfo:  ********************************
    GPSVC(338.27c) 10:55:30:518 GetGPOInfo:  Entering...
    GPSVC(338.27c) 10:55:30:533 GetMachineToken:  Looping for authentication again.
    GPSVC(338.27c) 10:55:30:580 GetMachineToken:  Looping for authentication again.
    GPSVC(338.27c) 10:55:30:596 GetMachineToken:  InitializeSecurityContext failed with 0x80090324
    GPSVC(338.27c) 10:55:30:596 GetGPOInfo:  Failed to get the machine token with  -2146893020
    GPSVC(338.27c) 10:55:30:596 GetGPOInfo:  Leaving with 0
    GPSVC(338.27c) 10:55:30:596 GetGPOInfo:  ********************************
    GPSVC(338.27c) 10:55:30:596 ProcessGPOs: GetGPOInfo failed.
    GPSVC(338.27c) 10:55:30:596 ProcessGPOs: No WMI logging done in this policy cycle.
    GPSVC(338.27c) 10:55:30:596 ProcessGPOs: Processing failed with error -2146893020.
    GPSVC(338.27c) 10:55:30:596 ProcessGPOs: Boot/Logon Policy processing - checking if UBPM trigger events need to be fired
    GPSVC(338.27c) 10:55:30:596 CheckAndFireGPTriggerEvent: Fired Policy present UBPM trigger event for Machine.
    GPSVC(338.27c) 10:55:30:596 Application complete with bConnectivityFailure = 0.
    GPSVC(338.27c) 10:55:30:596 Application complete with bConnectivityFailure = 0.
    GPSVC(338.4d0) 10:55:32:281 CGPNotify::RegisterForNotification: Entering with target Machine and event 0xd94
    GPSVC(338.4d0) 10:55:32:281 Client_InitialRegisterForNotification: User = machine, changenumber = 0
    GPSVC(338.4f0) 10:55:32:281 Target = Machine
    GPSVC(338.4d0) 10:55:32:281 Client_RegisterForNotification: User = machine, changenumber = 0
    GPSVC(338.4d0) 10:55:32:281 CGPNotify::RegisterForNotification: Exiting with status = 0
    GPSVC(338.384) 10:55:32:281 Target = Machine, ChangeNumber 0
    GPSVC(338.384) 10:55:35:900 SID = S-1-5-21-1599696121-1964574698-334091239-301107
    GPSVC(338.384) 10:55:35:900 bMachine = 0 
    GPSVC(338.384) 10:55:35:900 Setting GPsession state = 1
    GPSVC(338.384) 10:55:35:900 Message Status = <Applying user settings...>
    GPSVC(338.6c4) 10:55:35:900 Setting GPsession state = 1
    GPSVC(338.718) 10:55:35:900 StartTime For network wait: 11200ms
    GPSVC(338.718) 10:55:35:900 Current Time: 19546ms
    GPSVC(338.718) 10:55:35:900 MaxTimeToWaitForNetwork: 7034ms
    GPSVC(338.718) 10:55:35:900 TimeRemainingToWaitForNetwork: 0ms
    GPSVC(338.718) 10:55:35:900 UserPolicy: Waiting for machine policy wait for network event with timeout 0 ms
    GPSVC(338.718) 10:55:35:915 GPLockPolicySection: Sid = (null), dwTimeout = 30000, dwFlags = 65538
    GPSVC(338.718) 10:55:35:915 LockPolicySection called for user <Machine>
    GPSVC(338.718) 10:55:35:915 Sync Lock Called
    GPSVC(338.718) 10:55:35:915 Reader Lock got immediately. m_cReadersInLock : 1
    GPSVC(338.718) 10:55:35:915 Lock taken successfully
    GPSVC(338.718) 10:55:35:915 UnLockPolicySection called for user <Machine>
    GPSVC(338.718) 10:55:35:915 Found the caller in the ReaderHavingLock List. Removing it...
    GPSVC(338.718) 10:55:35:915 Setting lock state as notLocked
    GPSVC(338.718) 10:55:35:915 UnLocked successfully
    GPSVC(338.718) 10:55:35:915 GetDomainControllerConnectionInfo: Enabling bandwidth estimate.
    GPSVC(338.718) 10:55:36:430 Started bandwidth estimation successfully
    GPSVC(338.718) 10:55:36:430 GetDomainControllerConnectionInfo: Getting Ldap Handles.
    GPSVC(338.718) 10:55:36:430 GetLdapHandle:  Getting ldap handle for host: DC-MLIB.DOMAIN-NAME in domain: DOMAIN-NAME.
    GPSVC(338.718) 10:55:36:430 GetLdapHandle:  Server connection established.
    GPSVC(338.718) 10:55:36:430 GetLdapHandle:  Bound successfully.
    GPSVC(338.718) 10:55:36:430 ProcessGPOs: Computer's domain is same as user's domain so using user's domain DC
    GPSVC(338.718) 10:55:36:430 GetLdapHandle:  Getting ldap handle for host: DC-MLIB.DOMAIN-NAME in domain: <Unspecified>.
    GPSVC(338.718) 10:55:36:430 GetLdapHandle:  Server connection established.
    GPSVC(338.718) 10:55:36:446 GetLdapHandle:  Bound successfully.
    GPSVC(338.718) 10:55:36:446 ReadGPExtensions: Rsop entry point not found for C:\Windows\System32\dskquota.dll.
    GPSVC(338.718) 10:55:36:446 ReadGPExtensions: Rsop entry point not found for gptext.dll.
    GPSVC(338.718) 10:55:36:446 ReadGPExtensions: Rsop entry point not found for C:\Windows\System32\iedkcs32.dll.
    GPSVC(338.718) 10:55:36:446 ReadGPExtensions: Rsop entry point not found for C:\Windows\System32\iedkcs32.dll.
    GPSVC(338.718) 10:55:36:446 ReadGPExtensions: Rsop entry point not found for gptext.dll.
    GPSVC(338.718) 10:55:36:446 ReadGPExtensions: Rsop entry point not found for C:\Windows\System32\iedkcs32.dll.
    GPSVC(338.718) 10:55:36:446 ReadGPExtensions: Rsop entry point not found for gptext.dll.
    GPSVC(338.718) 10:55:36:446 ReadGPExtensions: Rsop entry point not found for gptext.dll.
    GPSVC(338.718) 10:55:36:446 ProcessGPOs:  No site name defined.  Skipping site policy.
    GPSVC(338.718) 10:55:36:446 GetGPOInfo:  ********************************
    GPSVC(338.718) 10:55:36:446 GetGPOInfo:  Entering...
    GPSVC(338.718) 10:55:36:446 SearchDSObject:  Searching <OU=People,DC=ad,DC=*****,DC=****>
    GPSVC(338.718) 10:55:36:446 SearchDSObject:  Found GPO(s):  < >
    GPSVC(338.718) 10:55:36:446 SearchDSObject:  Searching <DC=ad,DC=*****,DC=****>
    GPSVC(338.718) 10:55:36:446 SearchDSObject:  Found GPO(s):  <[LDAP://CN={31B2F340-016D-11D2-945F-00C04FB984F9},CN=Policies,CN=System,DC=ad,DC=*****,DC=****;0]>
    GPSVC(338.718) 10:55:36:446 ProcessGPO:  ==============================
    GPSVC(338.718) 10:55:36:446 ProcessGPO:  Deferring search for <LDAP://CN={31B2F340-016D-11D2-945F-00C04FB984F9},CN=Policies,CN=System,DC=ad,DC=*****,DC=****>
    GPSVC(338.718) 10:55:36:446 EvaluateDeferredGPOs:  Searching for GPOs in cn=policies,cn=system,DC=ad,DC=*****,DC=****
    GPSVC(338.718) 10:55:36:446 ProcessGPO:  ==============================
    GPSVC(338.718) 10:55:36:446 ProcessGPO:  Searching <CN={31B2F340-016D-11D2-945F-00C04FB984F9},CN=Policies,CN=System,DC=ad,DC=*****,DC=****>
    GPSVC(338.718) 10:55:36:446 ProcessGPO:  User has access to this GPO.
    GPSVC(338.718) 10:55:36:446 ProcessGPO:  GPO passes the filter check.
    GPSVC(338.718) 10:55:36:446 ProcessGPO:  Found functionality version of:  2
    GPSVC(338.718) 10:55:36:446 ProcessGPO:  Found file system path of:  <\\DOMAIN-NAME\sysvol\DOMAIN-NAME\Policies\{31B2F340-016D-11D2-945F-00C04FB984F9}>
    GPSVC(418.430) 17:59:09:821 CGPNotify::RegisterForNotification: Entering with target Machine and event 0x3dc
    GPSVC(418.430) 17:59:09:821 Client_InitialRegisterForNotification: User = machine, changenumber = 0
    GPSVC(338.6b8) 17:59:09:821 Target = Machine
    GPSVC(418.430) 17:59:09:821 Client_RegisterForNotification: User = machine, changenumber = 0
    GPSVC(418.430) 17:59:09:821 CGPNotify::RegisterForNotification: Exiting with status = 0
    GPSVC(338.30c) 17:59:09:821 Target = Machine, ChangeNumber 0
    GPSVC(418.430) 17:59:09:837 CGPNotify::RegisterForNotification: Entering with target Machine and event 0x448
    GPSVC(418.430) 17:59:09:837 Client_InitialRegisterForNotification: User = machine, changenumber = 0
    GPSVC(338.30c) 17:59:09:837 Target = Machine
    GPSVC(418.430) 17:59:09:837 Client_RegisterForNotification: User = machine, changenumber = 0
    GPSVC(418.430) 17:59:09:837 CGPNotify::RegisterForNotification: Exiting with status = 0
    GPSVC(338.6b8) 17:59:09:837 Target = Machine, ChangeNumber 0
    GPSVC(3b0.3c0) 17:59:11:085 CGPNotify::UnregisterNotification: Entering with event 0x16c
    GPSVC(3b0.3c0) 17:59:11:085 CGPNotify::AbortAsyncRegistration: No asyn registration is pending
    GPSVC(3b0.3c0) 17:59:11:085 CGPNotify::UnregisterNotification: Canceling pending calls
    GPSVC(3b0.3c0) 17:59:11:288 Client_CompleteNotificationCall: failed with 0x71a
    GPSVC(3b0.3c0) 17:59:11:288 CGPNotify::UnregisterNotification: Cancelled pending calls
    GPSVC(3b0.3c0) 17:59:11:288 CGPNotify::UnregisterNotification: Exiting with dwStatus = 0x0
    GPSVC(338.30c) 17:59:12:380 Target = Machine
    GPSVC(338.30c) 17:59:12:380 Target = Machine, ChangeNumber 0
    GPSVC(338.30c) 17:59:13:051 Target = Machine
    GPSVC(338.30c) 17:59:13:051 Target = Machine, ChangeNumber 0
    GPSVC(338.30c) 17:59:13:285 Target = Machine
    GPSVC(338.30c) 17:59:13:285 Target = Machine, ChangeNumber 0
    GPSVC(338.5a0) 17:59:14:143 CGPNotify::RegisterForNotification: Entering with target Machine and event 0xf04
    GPSVC(338.5a0) 17:59:14:143 Client_InitialRegisterForNotification: User = machine, changenumber = 0
    GPSVC(338.6b8) 17:59:14:143 Target = Machine
    GPSVC(338.5a0) 17:59:14:143 Client_RegisterForNotification: User = machine, changenumber = 0
    GPSVC(338.5a0) 17:59:14:143 CGPNotify::RegisterForNotification: Exiting with status = 0
    GPSVC(204.228) 17:59:59:897 CGPNotify::RegisterForNotification: Entering with target Machine and event 0xb50
    GPSVC(204.228) 17:59:59:897 Client_InitialRegisterForNotification: User = machine, changenumber = 0
    GPSVC(338.6b8) 17:59:59:897 Target = Machine
    GPSVC(204.228) 17:59:59:897 Client_RegisterForNotification: User = machine, changenumber = 0
    GPSVC(204.228) 17:59:59:897 CGPNotify::RegisterForNotification: Exiting with status = 0
    GPSVC(338.718) 18:01:58:941 ProcessGPO:  Found common name of:  <{31B2F340-016D-11D2-945F-00C04FB984F9}>
    GPSVC(338.718) 18:01:58:941 ProcessGPO:  Found display name of:  <Default Domain Policy>
    GPSVC(338.718) 18:01:58:941 ProcessGPO:  Found user version of:  GPC is 1, GPT is 1
    GPSVC(338.718) 18:01:58:941 ProcessGPO:  Found flags of:  0
    GPSVC(338.718) 18:01:58:941 ProcessGPO:  Found extensions:  [{3060E8D0-7020-11D2-842D-00C04FA372D4}{3060E8CE-7020-11D2-842D-00C04FA372D4}]
    GPSVC(338.718) 18:01:58:941 ProcessGPO:  ==============================
    GPSVC(338.718) 18:01:58:941 ProcessLocalGPO:  Local GPO's gpt.ini is not accessible, assuming default state.
    GPSVC(338.718) 18:01:58:941 ProcessLocalGPO:  GPO Local Group Policy doesn't contain any data since the version number is 0.  It will be skipped.
    GPSVC(338.718) 18:01:58:941 GetGPOInfo:  Leaving with 1
    GPSVC(338.718) 18:01:58:941 GetGPOInfo:  ********************************
    GPSVC(338.718) 18:01:58:941 GetGPOInfo:  ********************************
    GPSVC(338.718) 18:01:58:941 GetGPOInfo:  Entering...
    GPSVC(338.718) 18:01:59:097 SearchDSObject:  Searching <OU=FM-Security Video Servers,OU=FM-Servers,OU=FM,OU=Department OUs,DC=ad,DC=*****,DC=****>
    GPSVC(338.718) 18:01:59:097 SearchDSObject:  Found GPO(s):  <[LDAP://cn={B957D759-2AF4-4592-95B8-5B7C62F9B340},cn=policies,cn=system,DC=ad,DC=*****,DC=****;0]>
    GPSVC(338.718) 18:01:59:097 ProcessGPO:  ==============================
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  Deferring search for <LDAP://cn={B957D759-2AF4-4592-95B8-5B7C62F9B340},cn=policies,cn=system,DC=ad,DC=*****,DC=****>
    GPSVC(338.718) 18:01:59:113 SearchDSObject:  Searching <OU=FM-Servers,OU=FM,OU=Department OUs,DC=ad,DC=*****,DC=****>
    GPSVC(338.718) 18:01:59:113 SearchDSObject:  Found GPO(s):  <[LDAP://cn={E8A9990E-57AD-4B7B-BAE4-C56E20FB6314},cn=policies,cn=system,DC=ad,DC=*****,DC=****;0][LDAP://cn={251254DD-27DC-419F-816D-C51CDB309D8F},cn=policies,cn=system,DC=ad,DC=*****,DC=****;0]>
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  ==============================
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  Deferring search for <LDAP://cn={E8A9990E-57AD-4B7B-BAE4-C56E20FB6314},cn=policies,cn=system,DC=ad,DC=*****,DC=****>
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  ==============================
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  Deferring search for <LDAP://cn={251254DD-27DC-419F-816D-C51CDB309D8F},cn=policies,cn=system,DC=ad,DC=*****,DC=****>
    GPSVC(338.718) 18:01:59:113 SearchDSObject:  Searching <OU=FM,OU=Department OUs,DC=ad,DC=*****,DC=****>
    GPSVC(338.718) 18:01:59:113 SearchDSObject:  Found GPO(s):  <[LDAP://cn={1A42DA26-38F9-491C-940B-9D37895BE92A},cn=policies,cn=system,DC=ad,DC=*****,DC=****;1][LDAP://cn={F3D0434D-3EFF-4713-908C-3D8AB8189FB9},cn=policies,cn=system,DC=ad,DC=*****,DC=****;0][LDAP://cn={F03FA73B-A5B5-496B-94E5-5315D1D8F5F3},cn=policies,cn=system,DC=ad,DC=*****,DC=****;0][LDAP://cn={386C2C68-BB18-483B-AF36-92E76C1178D2},cn=policies,cn=system,DC=ad,DC=*****,DC=****;0][LDAP://cn={3D83F7A1-D4C2-4F8E-8808-CD5415D5A91E},cn=policies,cn=system,DC=ad,DC=*****,DC=****;0][LDAP://cn={462C2912-2318-4F46-A082-8BCC07EBDA29},cn=policies,cn=system,DC=ad,DC=*****,DC=****;0][LDAP://cn={7690B141-A1C2-4381-BD63-1AF5C09B4456},cn=policies,cn=system,DC=ad,DC=*****,DC=****;0][LDAP://cn={62C29217-3E25-42FC-8469-78312109323E},cn=policies,cn=system,DC=ad,DC=*****,DC=****;0][LDAP://cn={E795AC88-A750-45AF-870C-7EEDF00AA64A},cn=policies,cn=system,DC=ad,DC=*****,DC=****;0][LDAP://cn={B7C7410F-A3C0-4F12-8C3A-245C317EDFBA},cn=policies,cn=system,DC=ad,DC=*****,DC=****;0][LDAP://cn={CE1F85C1-DF2D-4E34-898B-2D6E3D0B55BE},cn=policies,cn=system,DC=ad,DC=*****,DC=****;0][LDAP://cn={D1B4C3BE-41CD-41B2-8A26-BE2EFD6953D0},cn=policies,cn=system,DC=ad,DC=*****,DC=****;0][LDAP://cn={E2673882-F33C-4879-AE75-583829D8BDA8},cn=policies,cn=system,DC=ad,DC=*****,DC=****;0][LDAP://cn={074DE127-4DBA-43F2-9C19-5953AD76CE9F},cn=policies,cn=system,DC=ad,DC=*****,DC=****;0][LDAP://cn={F4BAB9C5-0B6E-426B-93D3-1950A7002DC7},cn=policies,cn=system,DC=ad,DC=*****,DC=****;0][LDAP://cn={4A2C73AF-509F-4434-AF58-1AB3888959B4},cn=policies,cn=system,DC=ad,DC=*****,DC=****;0]>
    GPSVC(338.718) 18:01:59:113 SearchDSObject:  The link to GPO LDAP://cn={1A42DA26-38F9-491C-940B-9D37895BE92A},cn=policies,cn=system,DC=ad,DC=*****,DC=**** is disabled.  It will be skipped for processing.
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  ==============================
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  Deferring search for <LDAP://cn={F3D0434D-3EFF-4713-908C-3D8AB8189FB9},cn=policies,cn=system,DC=ad,DC=*****,DC=****>
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  ==============================
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  Deferring search for <LDAP://cn={F03FA73B-A5B5-496B-94E5-5315D1D8F5F3},cn=policies,cn=system,DC=ad,DC=*****,DC=****>
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  ==============================
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  Deferring search for <LDAP://cn={386C2C68-BB18-483B-AF36-92E76C1178D2},cn=policies,cn=system,DC=ad,DC=*****,DC=****>
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  ==============================
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  Deferring search for <LDAP://cn={3D83F7A1-D4C2-4F8E-8808-CD5415D5A91E},cn=policies,cn=system,DC=ad,DC=*****,DC=****>
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  ==============================
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  Deferring search for <LDAP://cn={462C2912-2318-4F46-A082-8BCC07EBDA29},cn=policies,cn=system,DC=ad,DC=*****,DC=****>
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  ==============================
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  Deferring search for <LDAP://cn={7690B141-A1C2-4381-BD63-1AF5C09B4456},cn=policies,cn=system,DC=ad,DC=*****,DC=****>
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  ==============================
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  Deferring search for <LDAP://cn={62C29217-3E25-42FC-8469-78312109323E},cn=policies,cn=system,DC=ad,DC=*****,DC=****>
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  ==============================
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  Deferring search for <LDAP://cn={E795AC88-A750-45AF-870C-7EEDF00AA64A},cn=policies,cn=system,DC=ad,DC=*****,DC=****>
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  ==============================
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  Deferring search for <LDAP://cn={B7C7410F-A3C0-4F12-8C3A-245C317EDFBA},cn=policies,cn=system,DC=ad,DC=*****,DC=****>
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  ==============================
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  Deferring search for <LDAP://cn={CE1F85C1-DF2D-4E34-898B-2D6E3D0B55BE},cn=policies,cn=system,DC=ad,DC=*****,DC=****>
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  ==============================
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  Deferring search for <LDAP://cn={D1B4C3BE-41CD-41B2-8A26-BE2EFD6953D0},cn=policies,cn=system,DC=ad,DC=*****,DC=****>
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  ==============================
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  Deferring search for <LDAP://cn={E2673882-F33C-4879-AE75-583829D8BDA8},cn=policies,cn=system,DC=ad,DC=*****,DC=****>
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  ==============================
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  Deferring search for <LDAP://cn={074DE127-4DBA-43F2-9C19-5953AD76CE9F},cn=policies,cn=system,DC=ad,DC=*****,DC=****>
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  ==============================
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  Deferring search for <LDAP://cn={F4BAB9C5-0B6E-426B-93D3-1950A7002DC7},cn=policies,cn=system,DC=ad,DC=*****,DC=****>
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  ==============================
    GPSVC(338.718) 18:01:59:113 ProcessGPO:  Deferring search for <LDAP://cn={4A2C73AF-509F-4434-AF58-1AB3888959B4},cn=policies,cn=system,DC=ad,DC=*****,DC=****>
    GPSVC(338.718) 18:01:59:113 SearchDSObject:  Searching <OU=Department OUs,DC=ad,DC=*****,DC=****>
    GPSVC(338.718) 18:01:59:113 SearchDSObject:  No GPO(s) for this object.
    GPSVC(338.718) 18:01:59:113 SearchDSObject:  Searching <DC=ad,DC=*****,DC=****>

    Thursday, April 9, 2015 12:07 AM

Answers

  • > GPSVC(338.350) 17:57:09:669 UnLocked successfully
    > GPSVC(338.27c) 10:55:29:426 Waiting for NETLOGON with timeout 6392
     
    The numbers in parenthesis are PID.TID of gpsvc.exe. So we see a thread
    change, and this usually indicates that a different logon process has
    begun. Could you try to map this log entries to events in the group
    policy event log?
     
    But to be honest: No, I've never seen such a behavior in gpsvc.log :(
    I'm almost sure that a service is responsible, but how to identify it -
    I don't know. There's no auditing for system time changes, AFAIK.
     

    Greetings/Grüße, Martin

    Mal ein gutes Buch über GPOs lesen?
    Good or bad GPOs? - my blog…
    And if IT bothers me - coke bottle design refreshment (-:
    Thursday, April 9, 2015 10:00 AM