Slow Logon | VMware Logon Monitor | Shell Load Time?

[vgerg]

Hi All,

I'm struggling with logon times so have enabled the VMware Logon Monitor, have configured it with the RemoteLogPath and configured the Connection Servers for the timingProfiler. It's a nested lab so I'm not expecting anything ground breaking with logon times. I'm struggling to find any information about exactly what the Shell Load Time means, other than "Windows provides the start time of the user shell load. The end time is when the explorer window is created." Could anyone expand on how I can debug this please?

I've followed the 'Creating an Optimized Windows Image for a VMware Horizon Virtual Desktop' to the letter.

Nested Lab

Horizon 7.5.3

vSphere 6.7 U3

Windows 10 1909, Horizon Agent 7.5.3, OSOT b1140, latest FSLogix, no other apps

AD Forest and Functional Level 2016

No KMS Server

Instant Clones, refresh at log off

2020-03-05T09:41:57.564 INFO (0c30-17cc) [LogonMonitor::LogSummary] ****************** Session Summary (User: LAB\greg.vdi, Session: 1) *****************

2020-03-05T09:41:57.564 INFO (0c30-17cc) [LogonMonitor::LogSummary] Logon Time: 17.53 seconds

2020-03-05T09:41:57.564 INFO (0c30-17cc) [LogonMonitor::LogSummary] Logon Start To Hive Loaded Time: 0.18 seconds

2020-03-05T09:41:57.564 INFO (0c30-17cc) [LogonMonitor::LogSummary] Logon Start To Classes Hive Loaded Time: 0.22 seconds

2020-03-05T09:41:57.564 INFO (0c30-17cc) [LogonMonitor::LogSummary] Profile Sync Time: 0.00 seconds

2020-03-05T09:41:57.564 INFO (0c30-17cc) [LogonMonitor::LogSummary] Windows Folder Redirection Apply Time: 0.00 seconds

2020-03-05T09:41:57.564 INFO (0c30-17cc) [LogonMonitor::LogSummary] Shell Load Time: 14.93 seconds

2020-03-05T09:41:57.564 INFO (0c30-17cc) [LogonMonitor::LogSummary] Total Logon Script Time: 0.00 seconds

2020-03-05T09:41:57.564 INFO (0c30-17cc) [LogonMonitor::LogSummary] User Policy Apply Time: 1 seconds

2020-03-05T09:41:57.564 INFO (0c30-17cc) [LogonMonitor::LogSummary] Machine Policy Apply Time: 0 seconds

2020-03-05T09:41:57.564 INFO (0c30-17cc) [LogonMonitor::LogSummary] Group Policy Software Install Time: 0.31 seconds

2020-03-05T09:41:57.564 INFO (0c30-17cc) [LogonMonitor::LogSummary] Free Disk Space Available To User: 21 GB

2020-03-05T09:41:57.564 INFO (0c30-17cc) [LogonMonitor::LogSummary] *************************************************************************************

Many thanks,

Gerg

[RoderikdeBlock]

According to the following thread this means:

The shell load time is the time it takes for the Window shell to load, i.e. Explorer.

Shell load time starts when Logon Monitor receives a notification from Windows when shell load is starting. It ends when the taskbar window is created

What is shell load time in Logon Monitor

[vgerg]

Hi Roderik,

Thanks for the explanation and links:-)

Is there a way to get more detailed information about what is going on during this phase? Log files, adding a GPO or reg key for further debugging?

I just logged in and timed from double clicking the pool to seeing the desktop, 42 seconds. I see the GPO etc applies very quickly, but the Preparing Windows took 30 seconds.

According to VMware Logon Monitor the logon was 18 seconds.

Any idea what is going on while it's "Preparing Windows" and how to get some granular information?

2020-03-05T10:45:07.419 INFO (0c40-15f8) [LogonMonitor::LogSummary] ****************** Session Summary (User: LAB\greg.vdi, Session: 2) *****************

2020-03-05T10:45:07.419 INFO (0c40-15f8) [LogonMonitor::LogSummary] Logon Time: 18.48 seconds

2020-03-05T10:45:07.419 INFO (0c40-15f8) [LogonMonitor::LogSummary] Logon Start To Hive Loaded Time: 0.20 seconds

2020-03-05T10:45:07.419 INFO (0c40-15f8) [LogonMonitor::LogSummary] Logon Start To Classes Hive Loaded Time: 0.25 seconds

2020-03-05T10:45:07.419 INFO (0c40-15f8) [LogonMonitor::LogSummary] Profile Sync Time: 0.00 seconds

2020-03-05T10:45:07.419 INFO (0c40-15f8) [LogonMonitor::LogSummary] Windows Folder Redirection Apply Time: 0.00 seconds

2020-03-05T10:45:07.419 INFO (0c40-15f8) [LogonMonitor::LogSummary] Shell Load Time: 15.02 seconds

2020-03-05T10:45:07.419 INFO (0c40-15f8) [LogonMonitor::LogSummary] Total Logon Script Time: 0.00 seconds

2020-03-05T10:45:07.419 INFO (0c40-15f8) [LogonMonitor::LogSummary] User Policy Apply Time: 1 seconds

2020-03-05T10:45:07.419 INFO (0c40-15f8) [LogonMonitor::LogSummary] Machine Policy Apply Time: 0 seconds

2020-03-05T10:45:07.419 INFO (0c40-15f8) [LogonMonitor::LogSummary] Group Policy Software Install Time: 0.66 seconds

2020-03-05T10:45:07.419 INFO (0c40-15f8) [LogonMonitor::LogSummary] Free Disk Space Available To User: 21 GB

2020-03-05T10:45:07.419 INFO (0c40-15f8) [LogonMonitor::LogSummary] *************************************************************************************

Thanks,

Gerg

[mrkasius]

Hi Gerg,

Possible you have configured "Run logon scripts synchronously". Since Windows Vista is a 30-second delay 'normal behaviour'. According to Microsoft KB940452, decrease the time-out interval to configure the value of the DelayedDesktopSwitchTimeout registry entry to 5 or a what fits best for your environment.