Windows 10 – Challenges with Logon time and Profile import

This post was originally published on this site

I know that there are a number of posts about long login times here in the community.
But it so happens that I still have big challenges with dissatisfied users, as our login times are over 1 minute for a user.
I understand that I have some challenges with DEM’s profile import, where some of the applications contain a little too much, and these are templates I have taken from VmWare’s website.
So I would think that this is the best practice to use them as they are. But of course I have also added several exclusions and inclusions to get what the users need.

Our company is located in 2 cities, and then has 2 sites, but the DEM server is located in site 1. The users have the DEM Profile area in their site, and the VDIs are also located in their respective sites.

I see in the logs the following logon time for 2 users, each belonging to its own site:

 

Site 1:

****************** Session Summary (User: domainuser1, Session: 1) *****************
Logon Time: 89.59 seconds
Logon Start To Hive Loaded Time: 0.00 seconds
Logon Start To Classes Hive Loaded Time: 9.62 seconds
Profile Sync Time: 8.32 seconds
Windows Folder Redirection Apply Time: 0.00 seconds
Shell Load Time: 9.76 seconds
Total Logon Script Time: 0.00 seconds
User Policy Apply Time: 69 seconds
Machine Policy Apply Time: 0 seconds
Group Policy Software Install Time: 0.09 seconds
Free Disk Space Available To User: 42 GB
**********************************************************************************

Site 2:

****************** Session Summary (User: domainuser2, Session: 1) *****************
Logon Time: 71.26 seconds
Logon Start To Hive Loaded Time: 0.00 seconds
Logon Start To Classes Hive Loaded Time: 27.65 seconds
Profile Sync Time: 26.38 seconds
Windows Folder Redirection Apply Time: 0.00 seconds
Shell Load Time: 5.51 seconds
Total Logon Script Time: 0.00 seconds
User Policy Apply Time: 34 seconds
Machine Policy Apply Time: 0 seconds
Group Policy Software Install Time: 0.23 seconds
Free Disk Space Available To User: 41 GB
**********************************************************************************

 

The pool both log on to is based on the same Golden image, which has been cloned from site 1 to site 2

When I go through the logs I see the following for user 1:
T10:33:32.160 TRACE (0dd4-075c) [LogonMonitor::ProcessGroupPolicyEvent] Event Id: 4016, ActivityID: {39C1E896-768C-4BC9-937B-9B23DCC4762D}, Account: , Session: 1

T10:34:39.075 TRACE (0dd4-075c) [LogonMonitor::ProcessGroupPolicyEvent] Event Id: 5016, ActivityID: {39C1E896-768C-4BC9-937B-9B23DCC4762D}, Account: , Session: 1


For user 2, the time is a little lower:
T08:40:44.871 TRACE (1080-0728) [LogonMonitor::ProcessGroupPolicyEvent] Event Id: 4016, ActivityID: {6A47075B-EBDB-476E-B436-38D8CC1AFE5C}, Account: , Session: 1

T08:41:17.403 TRACE (1080-1aa4) [LogonMonitor::ProcessGroupPolicyEvent] Event Id: 4016, ActivityID: {6A47075B-EBDB-476E-B436-38D8CC1AFE5C}, Account: , Session: 1

What is going on here?
Does the machine spend more than 1 minute on a GPO, or is it DEM that uses this time?

 

When the profile import starts, I can see the following:

T10:33:20.504 INFO (0dd4-075c) [LogonMonitor::Logon] LOGON: User: domainuser1, Session: 1
T10:33:21.397 TRACE (0dd4-075c) [LogonMonitor::ProcessLogonEvent] Event Id: 1, Session: 1
T10:33:21.397 TRACE (0dd4-075c) [LogonMonitor::ProcessLogonEvent] Profile Started. Session: 1
T10:33:21.397 TRACE (0dd4-0364) [LogonMonitor::ProcessLogonEvent] Event Id: 6, Session: 1
T10:33:21.397 TRACE (0dd4-0364) [LogonMonitor::ProcessLogonEvent] Profile Sync Started. Session: 1
T10:33:29.968 TRACE (0dd4-0364) [LogonMonitor::ProcessLogonEvent] Event Id: 7, Session: 1
T10:33:29.968 TRACE (0dd4-0364) [LogonMonitor::ProcessLogonEvent] Profile Sync Finished. Session: 1
T10:33:29.968 TRACE (0dd4-075c) [LogonMonitor::ProcessLogonEvent] Event Id: 5, Session: 1
T10:33:31.032 TRACE (0dd4-075c) [LogonMonitor::ProcessLogonEvent] Event Id: 5, Session: 1


T08:40:14.892 INFO (1080-0dc0) [LogonMonitor::Logon] LOGON: User: domainuser2, Session: 1
T08:40:15.775 TRACE (1080-0dc0) [LogonMonitor::ProcessLogonEvent] Event Id: 1, Session: 1
T08:40:15.775 TRACE (1080-0dc0) [LogonMonitor::ProcessLogonEvent] Profile Started. Session: 1

T08:40:15.775 TRACE (1080-0728) [LogonMonitor::ProcessLogonEvent] Event Id: 6, Session: 1
T08:40:15.775 TRACE (1080-0728) [LogonMonitor::ProcessLogonEvent] Profile Sync Started. Session: 1
T08:40:42.650 TRACE (1080-0728) [LogonMonitor::ProcessLogonEvent] Event Id: 7, Session: 1
T08:40:42.650 TRACE (1080-0728) [LogonMonitor::ProcessLogonEvent] Profile Sync Finished. Session: 1
T08:40:42.650 TRACE (1080-0dc0) [LogonMonitor::ProcessLogonEvent] Event Id: 5, Session: 1
T08:40:42.650 TRACE (1080-0dc0) [LogonMonitor::ProcessLogonEvent] Event Id: 5, Session: 1

 

What is going on here?
User 2 has a much smaller profile to be imported than user 1, but DEM is located in the site of user 1. The profile areas are located in the user’s site, respectively.
How can we monitor this job more deeply so that we can pin point what takes so long?

Are there any tools that allow me to easily see which application import takes the longest time?


***************SYSTEM***************

Windows 10: 10.0.18362.1016
RAM: 10GB
Instant Clone – Non presistant desktops
DEM: 9.10.0.921
Horizon: 7.10.1
4 CS in each site
1 Vcenter in each site (for Office clients)
About 90-140 sessions per site

*************************************

Leave a Reply

This site uses Akismet to reduce spam. Learn how your comment data is processed.