Troubleshooting slow logins.

[lansti]

I'm looking into our logons, where users experience logon time beween 60 to 90 seconds, which i meen is too slow logon.

When i have a look at the vmware logon monitor i see that my user often end up with a logon  around 60 seconds:

2019-01-04T09:27:38.242 INFO (09f0-1220) [LogonMonitor::LogSummary] ****************** Session Summary (User: DOAMIN\user, Session: 1) *****************

2019-01-04T09:27:38.242 INFO (09f0-1220) [LogonMonitor::LogSummary] Logon Time: 61.32 seconds

2019-01-04T09:27:38.242 INFO (09f0-1220) [LogonMonitor::LogSummary] Logon Start To Hive Loaded Time: 0.00 seconds

2019-01-04T09:27:38.242 INFO (09f0-1220) [LogonMonitor::LogSummary] Logon Start To Classes Hive Loaded Time: 3.73 seconds

2019-01-04T09:27:38.242 INFO (09f0-1220) [LogonMonitor::LogSummary] Profile Sync Time: 3.19 seconds

2019-01-04T09:27:38.242 INFO (09f0-1220) [LogonMonitor::LogSummary] Windows Folder Redirection Apply Time: 0.00 seconds

2019-01-04T09:27:38.242 INFO (09f0-1220) [LogonMonitor::LogSummary] Shell Load Time: 6.60 seconds

2019-01-04T09:27:38.242 INFO (09f0-1220) [LogonMonitor::LogSummary] Total Logon Script Time: 0.00 seconds

2019-01-04T09:27:38.242 INFO (09f0-1220) [LogonMonitor::LogSummary] User Policy Apply Time: 49 seconds

2019-01-04T09:27:38.242 INFO (09f0-1220) [LogonMonitor::LogSummary] Machine Policy Apply Time: 0 seconds

2019-01-04T09:27:38.242 INFO (09f0-1220) [LogonMonitor::LogSummary] Group Policy Software Install Time: 0.23 seconds

2019-01-04T09:27:38.242 INFO (09f0-1220) [LogonMonitor::LogSummary] Free Disk Space Available To User: 56 GB

2019-01-04T09:27:38.242 INFO (09f0-1220) [LogonMonitor::LogSummary] ***********************************************************************************

is it possible to point out where the seconds are running from vmlm.txt log or vmlm__CLIENTNAME_USERNAME_date.txt log?

I see this is my vmlm__CLIENTNAME_USERNAME_date.txt log, 15 seconds running away..:

2019-01-04T10:11:16.995 TRACE (0b3c-130c) [LogonMonitor::ProcessGroupPolicyEvent] Event Id: 4016, ActivityID: {D589478B-B6C6-49AF-887C-DECCFB5C0398}, Account: , Session: 1

2019-01-04T10:11:31.995 TRACE (0b3c-082c) [LogonMonitor::ProcessGroupPolicyEvent] Event Id: 4016, ActivityID: {D589478B-B6C6-49AF-887C-DECCFB5C0398}, Account: , Session: 1

And from the vmlm.txt log:

about 6 seconds here:

2019-01-04T09:26:36.978 DEBUG (09f0-044c) [WinlogonNotifyLogEnd] WinlogonNotify completed OnLogon, pLogonData: 0000000001DEE9A0, Duration (ms): 113

2019-01-04T09:26:42.341 TRACE (09f0-0b14) [LogonMonitor::ProcessGroupPolicyEvent] Failed to find Session for User PolicyEvent Id: 5326, ActivityID: {2AEE89DF-BACA-42DE-895F-6C618CE405AF}, Account:

10 seconds here:

2019-01-04T09:26:47.349 TRACE (09f0-0a0c) [MailslotServer::ProcessMessage] Begin event: Product: UEM Agent, Component: FlexEngine, Event: Import, Event Type: EVENT_BEGIN, Process Id: 288, Timestamp: 2019-01-04T09:26:47.349, Session: 1

2019-01-04T09:26:57.095 TRACE (09f0-0a0c) [MailslotServer::ProcessMessage] End event: Product: UEM Agent, Component: FlexEngine, Event: Import, Event Type: EVENT_END, Process Id: 288, Timestamp: 2019-01-04T09:26:57.095, Session: 1

12 seconds here:

2019-01-04T09:26:57.095 TRACE (09f0-0a0c) [MailslotServer::ProcessMessage] Begin event: Product: UEM Agent, Component: FlexEngine, Event: Post-import, Event Type: EVENT_BEGIN, Process Id: 288, Timestamp: 2019-01-04T09:26:57.095, Session: 1

2019-01-04T09:27:09.963 TRACE (09f0-0a0c) [MailslotServer::ProcessMessage] End event: Product: UEM Agent, Component: FlexEngine, Event: Post-import, Event Type: EVENT_END, Process Id: 288, Timestamp: 2019-01-04T09:27:09.963, Session: 1

15 seconds:

2019-01-04T09:27:15.771 TRACE (09f0-0a0c) [MailslotServer::ProcessMessage] End event: Product: UEM Agent, Component: FlexEngine, Event: Async, Event Type: EVENT_END, Process Id: 4792, Timestamp: 2019-01-04T09:27:15.771, Session: 1

2019-01-04T09:27:30.529 TRACE (09f0-0a0c) [MailslotServer::ProcessMessage] End event: Product: AppVolumes, Component: svservice, Event: Login, Event Type: EVENT_END, Process Id: 932, Timestamp: 2019-01-04T09:27:30.529, Session: 0

[ubruns]

Hi lansti!

I think this will come from some user policy setting. It consumes 49 seconds of the 61:

2019-01-04T09:27:38.242 INFO (09f0-1220) [LogonMonitor::LogSummary] User Policy Apply Time: 49 seconds

So, check the user part of your policy. Maybe you try to install some software or something ???

[lansti]

i noticed that, but is these 49 seconds both GPO user policy AND UEM?

[ubruns]

Uhh... that's beyond my knowledge.

Maybe the "VMware Logon Monitor" will support you to find the issue:

VMware Logon Monitor

[sjesse]

UEM get applied at the same time as GPOs if I remember right. I'd remove any user GPOs temprararly and see if that improves the logon times. I saw something similar for gpos our security team was applying, I now manually put those changes in the parent image and that improved our logon times.

[lansti]

Yes, i have gone through some of my policyes, and there is a lot of policyes that no longer are needed, and so far it seems that the logontime is almost cut 50%... for the record: this is testet in my test environment, and i'll work futher with it next week, deploy and test updated GPOs to mye production environment.

[lansti]

I have managed to get a logontime about 25 seconds.

Logon time 25,6 seconds

Shell 6,95 seconds

User policy 17 seconds.

This is from a laptop with horizon 4.9.0

When i log on to the same image from Dell Wyse 5060p:

Logon time 39,30 seconds

Shell 21,26 seconds

User policy 16 seconds

With a zero klient(5030) we got this logon time:

Logon time 23,64 seconds

Shell 6,37 seconds

User policy 15 seconds

is the logon delay we see in Dell Wyse 5060p related to network or horizon agent installed on thinos?

Have you seen this issue somewhere UEMdev​?

[DEMdev]

Hi lansti,

If you run UEM as a Group Policy client-side extension, it will be counted against VMLM's User Policy Apply Time. If you want to know what exactly is going on with UEM, VMLM does not provide much insight, so you'd need to take a look at the UEM agent's log file.

[lansti]

My logs are telling me the same, either i log on a thinos client or laptop.

But i see that loading shell take like 15-20 seconds longer on a ThinOS (Dell wyse 5060p), as i mentioned in my post. And i cant see why it takes so much longer time during logon...

[larstr]

lansti,

There should in be any difference if the setup is the same. So I'm wondering:

• Are the different clients on the same network? If not, are firewall rules, dns config for subnets(+reverse) same?
• Are both using the same protocol (PCoIP / Blast / RDP)?
• Do any of them have external peripherals other than mouse/keyboard?

Lars

[nettech1]

are they linked or instant clones?