Becoming an WPA Xpert Part 12: Timing User Login Credentials (Sometimes it IS the user)

Hi everyone here is Randy Reyes with a much needed updated to our slow boot slow login (sbsl) series. It’s been a while since our last entry and I ran into an interesting customer question.

Customer: Can we see how long takes an employee to type their user name and password?

Randy: Thanks to WPT the answer is yes.

The customer provided me with the trace from the last known time the user log in.

So let’s get to it.

The Before

PreSMSS

SMSSInit

WinlogonInit

ExplorerInit

Post Boot

3.973

7.433

45.502

0.998

18.800

Boot to Post Boot Activity ended: 72.734 Seconds and 734 Milliseconds = 1 Minute and 12 Seconds

image

Now you might be saying to yourself, 1 min and 12 seconds is not too bad. Since I only received the trace and no other information I didn’t have any idea in how much memory, CPU or disk speed are in this particular host. I decided to check the specs.

In order to start looking at the specs we go to the tab Trace, then System and then General.

image

Next, Storage

image

What if I told you it was a SSD (solid state drive)? Would you consider 1 minute and 12 seconds to be an optimal value? I’ve discussed some optimal times in a previous post, “Becoming an Xperf Xpert Part 7: Slow Profile Load and Our Very First Stack Walk”. Based on the hardware specs it looks like this machine should be booting faster.

The major delay in the boot trace can be identified in the Winlogon Phase (45 seconds). Many operations occur in parallel during WinLogonInit. On many systems, this phase is CPU bound and has large I/O demands. Services like PnP and Power, network subsystem, Computer and User Group Policy processing, CAD (CTRL+ALT+DEL) screen and credentials input can all lead to a delay. Good citizenship from the services that start in this phase is critical for optimized boot times.

To start we are going expand the System Activity graph group and we are going to add the graph Generic Events using table only.

image

After arranging the tables (Provider Name, Task Name) and the golden bar, the first issue detected was under Microsoft-Windows-Winlogon provider. The Task Name Display Welcome Screen aka CTRL+ALT+DEL was available to the user at 8.764 seconds of the trace. But he enters the combination in the keyboard at 18.055 of the trace.

Subtracting these times with get 9.295 seconds just waiting for the user to press CTRL+ALT+DEL.

image

Next issue detected in this particular trace is located under the Task Name Request Credential. Looks like the user entered the user name and password in 3 different times. First try was at 18.692 seconds of the trace at 39.59, again at 40.951 to 48.160 and finally at 48.958 to 51.012.

image

Looks like either the username, the password or one of the two were incorrectly typed and the access was denied.

At this point I explain the customer between the 9.295 seconds spent waiting to press CRTL+ALT+DEL and 32.392 seconds with possible wrong typed credentials. This will probably be the reason of the long delay for the user.

This solution was a simple one request the user to log in again with proper credentials, the results are in the picture below.

The After

Boot to Post Boot Activity end: 39 Seconds and 373 Milliseconds

image

We probably have a bit more work to do to continue to optimize but we are heading in the right direction.

All the previous SBSL articles can be found at http://blogs.technet.com/b/askpfeplat/archive/tags/sbsl/

If you are really excited and want to run this tool on Window 10 Preview here is other blogs from good friend Yong Rhee

WPT: Updated version of “Windows Performance Toolkit” from Windows 10 Technical Preview ADK or SDK

http://blogs.technet.com/b/yongrhee/archive/2015/03/21/wpt-updated-version-of-windows-performance-toolkit-10-technical-preview-from-the-adk.aspx

Randy “Why does this keep happening to me” Reyes