Jump to content
Welcome to our new Citrix community!
  • 0

UPM (VDA 2103) - at least 50% of the time getting new profile on logon


Question

Hi all,

Having an issue been battling with our VDI environment last couple of weeks:

 

Environment

CVAD 1912 CU2

Non-persistent VDI Windows 20h2 - VDA 2103

 

On nearly every other logon (could be 3 logons out of 4 but generally more than half the time) users will get a new profile even though they have roaming profile stored in a DFS path - their flexupm folder has other OS folders and no issues. Other quirk is with the "new" profile it cant copy itself back as when it tries to it says the user store already has one

In essence

 

Stuff ruled out

AV disabled 

Verified GPO's etc processing fine 

I have checked the logs uploaded:

•    Good login:
2021-05-06;06:56:27.374;INFORMATION;;;1;4976;DispatchLogonLogoff: ---------- Starting logon processing...
2021-05-06;06:56:27.374;INFORMATION;;;1;4976;IsRunningInTerminalServerSession: Workstation found. Console session.
2021-05-06;06:56:27.374;INFORMATION;;;1;4976;ImpersonateClientStart: Successfully impersonated a client.
2021-05-06;06:56:27.374;INFORMATION;ACME;Mickeymouse;1;4976;ImpersonateClientStop: Successfully stopped client impersonation.
2021-05-06;06:56:27.374;INFORMATION;ACME;Mickeymouse;1;4976;DispatchLogonLogoff: UserSID = S-1-5-21-137981764-1709787988-231145771-144716
2021-05-06;06:56:28.780;INFORMATION;ACME;Mickeymouse;1;4976;DispatchLogonLogoff: Triggered policy evaluation for <S-1-5-21-137981764-1709787988-231145771-144716>
2021-05-06;06:56:28.780;INFORMATION;ACME;Mickeymouse;1;4976;DispatchLogonLogoff: Updated Group Policy Extension history for <S-1-5-21-137981764-1709787988-231145771-144716>
2021-05-06;06:56:28.858;INFORMATION;ACME;Mickeymouse;1;4976;ImpersonateClientStart: Successfully impersonated a client.
2021-05-06;06:56:28.858;INFORMATION;ACME;Mickeymouse;1;4976;CheckUserExistsInGroup: No Entries Found In ExcludedGroups
2021-05-06;06:56:28.858;INFORMATION;ACME;Mickeymouse;1;4976;CheckUserExistsInGroup: No Entries Found In ProcessedGroups
2021-05-06;06:56:28.858;INFORMATION;ACME;Mickeymouse;1;4976;CheckIfUserNeedsToBeProcessed: Logon/logoff will be processed.
2021-05-06;06:56:28.858;INFORMATION;ACME;Mickeymouse;1;4976;GetUserStorePath: User Store: Path In: \\ACME.net\enterprise\Services\VAD\Home\AMR\#SAMAccountName#\FlexUPM\!ctx_osname!
2021-05-06;06:56:28.858;INFORMATION;ACME;Mickeymouse;1;4976;CADUser::Init: Determined user and DNS domain name: <ACMEuser>, <ACME.NET>
2021-05-06;06:56:28.889;INFORMATION;ACME;Mickeymouse;1;4976;CADUser::Init: Determined the ADsPath of user: <ACMEuser>: <LDAP://ACME.NET/CN=ACMEuser\, John (ACMEuser),OU=Users,OU=IEDUB,OU=Western Europe,DC=ACME,DC=net>
2021-05-06;06:56:28.889;INFORMATION;ACME;Mickeymouse;1;4976;GetUserStorePath: User Store: Path Out: \\ACME.net\enterprise\services\vad\home\amr\ACMEuser\flexupm\Win10_2009
2021-05-06;06:56:28.889;INFORMATION;ACME;Mickeymouse;1;4976;ImpersonateClientStop: Successfully stopped client impersonation.
2021-05-06;06:56:34.280;INFORMATION;ACME;Mickeymouse;1;4976;XenApp Optimization, enabled: 0, definition path: 
2021-05-06;06:56:34.280;INFORMATION;ACME;Mickeymouse;1;4976;SessionCount:RealTimeCount - Detected a Client OS, not using WTS calls 
2021-05-06;06:56:34.280;INFORMATION;ACME;Mickeymouse;1;4976;SessionCount::RealTimeCount - User: ACMEuser, Domain: ACME-DOMAIN, Session Count: 0.
2021-05-06;06:56:34.280;INFORMATION;ACME;Mickeymouse;1;4976;ImpersonateClientStart: Successfully impersonated a client.
2021-05-06;06:56:34.483;INFORMATION;ACME;Mickeymouse;1;4976;ProcessLogon: Found a profile in the user store: <\\ACME.net\enterprise\services\vad\home\amr\ACMEuser\flexupm\Win10_2009>.


•    Bad login: new profile created
2021-05-06;07:07:57.122;INFORMATION;;;1;508;DispatchLogonLogoff: ---------- Starting logon processing...
2021-05-06;07:07:57.122;INFORMATION;;;1;508;IsRunningInTerminalServerSession: Workstation found. Console session.
2021-05-06;07:07:57.122;INFORMATION;;;1;508;ImpersonateClientStart: Successfully impersonated a client.
2021-05-06;07:07:57.122;INFORMATION;ACME;Mickeymouse;1;508;ImpersonateClientStop: Successfully stopped client impersonation.
2021-05-06;07:07:57.122;INFORMATION;ACME;Mickeymouse;1;508;DispatchLogonLogoff: UserSID = S-1-5-21-137981764-1709787988-231145771-144716
2021-05-06;07:07:59.279;INFORMATION;ACME;Mickeymouse;1;508;DispatchLogonLogoff: Triggered policy evaluation for <S-1-5-21-137981764-1709787988-231145771-144716>
2021-05-06;07:07:59.279;INFORMATION;ACME;Mickeymouse;1;508;DispatchLogonLogoff: Updated Group Policy Extension history for <S-1-5-21-137981764-1709787988-231145771-144716>
2021-05-06;07:07:59.357;INFORMATION;ACME;Mickeymouse;1;508;ImpersonateClientStart: Successfully impersonated a client.
2021-05-06;07:07:59.357;INFORMATION;ACME;Mickeymouse;1;508;CheckUserExistsInGroup: No Entries Found In ExcludedGroups
2021-05-06;07:07:59.357;INFORMATION;ACME;Mickeymouse;1;508;CheckUserExistsInGroup: No Entries Found In ProcessedGroups
2021-05-06;07:07:59.357;INFORMATION;ACME;Mickeymouse;1;508;CheckIfUserNeedsToBeProcessed: Logon/logoff will be processed.
2021-05-06;07:07:59.357;INFORMATION;ACME;Mickeymouse;1;508;GetUserStorePath: User Store: Path In: \\ACME.net\enterprise\Services\VAD\Home\AMR\#SAMAccountName#\FlexUPM\!ctx_osname!
2021-05-06;07:07:59.357;INFORMATION;ACME;Mickeymouse;1;508;CADUser::Init: Determined user and DNS domain name: <ACMEuser>, <ACME.NET>
2021-05-06;07:07:59.388;INFORMATION;ACME;Mickeymouse;1;508;CADUser::Init: Determined the ADsPath of user: <ACMEuser>: <LDAP://ACME.NET/CN=ACMEuser\, John (ACMEuser),OU=Users,OU=IEDUB,OU=Western Europe,DC=ACME,DC=net>
2021-05-06;07:07:59.388;INFORMATION;ACME;Mickeymouse;1;508;GetUserStorePath: User Store: Path Out: \\ACME.net\enterprise\services\vad\home\amr\ACMEuser\flexupm\Win10_2009
2021-05-06;07:07:59.388;INFORMATION;ACME;Mickeymouse;1;508;ImpersonateClientStop: Successfully stopped client impersonation.
2021-05-06;07:08:02.888;INFORMATION;ACME;Mickeymouse;1;508;XenApp Optimization, enabled: 0, definition path: 
2021-05-06;07:08:02.888;INFORMATION;ACME;Mickeymouse;1;508;SessionCount:RealTimeCount - Detected a Client OS, not using WTS calls 
2021-05-06;07:08:02.888;INFORMATION;ACME;Mickeymouse;1;508;SessionCount::RealTimeCount - User: ACMEuser, Domain: ACME-DOMAIN, Session Count: 0.
2021-05-06;07:08:02.888;INFORMATION;ACME;Mickeymouse;1;508;ImpersonateClientStart: Successfully impersonated a client.
2021-05-06;07:08:02.950;INFORMATION;ACME;Mickeymouse;1;508;NTUSER.DAT not found in userstore, try to load NTUSER.DAT.LASTGOODLOAD.
2021-05-06;07:08:02.950;ERROR;ACME;Mickeymouse;1;508;UpmUserStore::UpdateNtuserDatWithLastGoodLoad: There is no NTUSER.DAT.LASTGOODLOAD in the path:\\ACME.net\enterprise\services\vad\home\amr\ACMEuser\flexupm\Win10_2009\UPM_Profile\NTUSER.DAT.LASTGOODLOAD 0x2. The system cannot find the file specified.

2021-05-06;07:08:02.982;INFORMATION;ACME;Mickeymouse;1;508;ImpersonateClientStop: Successfully stopped client impersonation.
2021-05-06;07:08:02.982;INFORMATION;ACME;Mickeymouse;1;508;QueryLocalProfile: No profile directory found.
2021-05-06;07:08:02.982;INFORMATION;ACME;Mickeymouse;1;508;QueryLocalProfile: Determined the name of a new profile directory: <C:\Users\ACMEuser>.
2021-05-06;07:08:02.982;INFORMATION;ACME;Mickeymouse;1;508;ImpersonateClientStart: Successfully impersonated a client.
2021-05-06;07:08:02.982;INFORMATION;ACME;Mickeymouse;1;508;ProcessLogon: Did not find a profile in the user store: <\\ACME.net\enterprise\services\vad\home\amr\ACMEuser\flexupm\Win10_2009>.
 

•    When copying back local profile to user store path, the profile is found:
2021-05-06;07:08:05.560;INFORMATION;ACME;Mickeymouse;1;508;MigrateLocalProfileToUserStore: Starting to migrate a local profile from <C:\Users\ACMEuser> to <\\ACME.net\enterprise\services\vad\home\amr\ACMEuser\flexupm\Win10_2009>...
2021-05-06;07:08:05.919;ERROR;ACME;Mickeymouse;1;508;MigrateLocalProfileToUserStore: The user store already contains a profile! Possibly a second session has migrated into the user store in the meantime. Aborting...
2021-05-06;07:08:05.919;INFORMATION;ACME;Mickeymouse;1;508;ImpersonateClientStop: Successfully stopped client impersonation.
2021-05-06;07:08:05.919;ERROR;ACME;Mickeymouse;1;508;CreateLocalProfileFromTemplate: Could not create a local profile from a template: Cannot create a file when that file already exists.
2021-05-06;07:08:05.919;ERROR;ACME;Mickeymouse;1;508;ProcessLogon: SetupLocalProfile failed
2021-05-06;07:08:05.919;INFORMATION;ACME;Mickeymouse;1;508;ImpersonateClientStart: Successfully impersonated a client.
2021-05-06;07:08:06.122;INFORMATION;ACME;Mickeymouse;1;508;ImpersonateClientStop: Successfully stopped client impersonation.
2021-05-06;07:08:06.122;INFORMATION;ACME;Mickeymouse;1;508;DispatchLogonLogoff: Updated Group Policy Extension history for <S-1-5-21-137981764-1709787988-231145771-144716>
2021-05-06;07:08:06.122;INFORMATION;ACME;Mickeymouse;1;508;DispatchLogonLogoff: ---------- Finished logon processing successfully in [s]: <9.00>.
 

Conclusion:
-    UPM does not find the profile and therefore it creates a new local profile from Default user, expected behavior
-    Then migrates the local created profile to the user store and then it is when it finds that the profile has been created

 

 

Any assistance be helpful - driving us crackers

Link to comment

3 answers to this question

Recommended Posts

  • 0

1 target for the DFS path. Interestingly i noticed something else this morning:

 

i Euro data center - same image - different profile policy (but essentially same with different user store path - works

ii) Americas data center -#1 (Vmware hosted - PVS) same image - Americas profile GPO - with the issue

iii) Americas data center #2 (around the corner from #1) - same image (except for nutanix drivers) - same policy as ii) - works

 

Only differential i could find is:

i) Different AD site and thus controllers

 

When it doesnt work i can still browse to the path fine within the session it just will refuse to take down the roaming profile - have network traces in with the vendor but i am not hopeful

 

Link to comment
  • 0

1 target for the DFS path. Interestingly i noticed something else this morning:

 

i Euro data center - same image - different profile policy (but essentially same with different user store path - works

ii) Americas data center -#1 (Vmware hosted - PVS) same image - Americas profile GPO - with the issue

iii) Americas data center #2 (around the corner from #1) - same image (except for nutanix drivers) - same policy as ii) - works

 

Only differential i could find is:

i) Different AD site and thus controllers

 

When it doesnt work i can still browse to the path fine within the session it just will refuse to take down the roaming profile - have network traces in with the vendor but i am not hopeful

 

UPDATE - found it is somehow related to AV - when we disable AV the issue goes away

Link to comment

Create an account or sign in to comment

You need to be a member in order to leave a comment

Create an account

Sign up for a new account in our community. It's easy!

Register a new account

Sign in

Already have an account? Sign in here.

Sign In Now
×
×
  • Create New...