Case of the 8 Minute Windows 8.1 First Logon

In this case Windows 8.1 was slow to logon, only for the first logon. But it was slow….

Typically for slow logons / startups on Windows machines my go-to tools are

1) The Windows Event logs. Besides the System / Application logs don’t forget the logs under Microsoft\Windows section in Event Viewer. Such as

• Microsoft-Windows-Diagnostics-Performance/Operational
• Microsoft-Windows-OfflineFiles/Operational
• Microsoft-Windows-GroupPolicy/Operational

In some cases the debug versions of logs can be used, these need to be enabled –> Event Viewer –> Show Analytic and Debug Logs, then right click the individual debug log to enable and click Enable

2) AutoRuns – for checking/exporting/comparing startup items/Active Setups/etc http://live.sysinternals.com/autoruns.exe

2) Windows Performance Recorder / XPerf – from the Windows ADK

3) ProcMon – boot trace

4) Packet Capture – In Windows 7 and later a boot network trace can be captured with netsh trace start capture=yes persistent=yes report=yes The persistent option will keep network trace running when you reboot. After logging on netsh trace stop. Note: You may need to increase the default log size from 250MB for some types of slow logon situations, these options are in netsh trace start /?

In this case we’ll start with Windows Performance Recorder (wprui.exe). If copying to a user’s machine I just typically copy the folder, rather than installing ADK on user’s machine. From the Windows 8.1 ADK on a 64-bit machine this folder will be C:\Program Files (x86)\windows kits\8.1\Windows Performance Toolkit

For an initial boot analysis typically I use these settings:

• First level triage
• CPU Usage
• Disk I/O Activity
• File I/O Activity
• Networking I/O Activity
• Performance Scenario: Boot
• Number of Iterations: 1

Clicking Start you will be prompted to describe the scenario, then to reboot to kick off the trace.

Once the trace is available, we open the file in Windows Performance Analyzer (wpa.exe)

Note: I find WPA frequently crashes opening large (5GB+) traces on machines with less than 4 GB ram.

Typically I start expanding System Activity and check the Boot Phases section to identify where delay is.

These phases correspond to the following:

• Pre-Session Init. BIOS firmware performs power-on self-test and executes preboot instructions, searching for bootable media
• Session Init. Loading kernel and pre-boot related services. Long delays in this session are most often related to Video Drivers, BIOS, or some other driver. If an update is available, update the BIOS.
• Winlogon Init. Starting more services, authenticating machine account, logging on user
• Explorer Init. User has been authenticated, but desktop is being created, at the end of this phase, the desktop appears.
• Post Boot. The desktop has appeared, but system may still not be usable due to scenarios such as overwhelmed disk from applications and services starting up.

Looking at our case we can see the Winlogon Init, Explorer Init and Bost Poot phase is very long

For Windows 7 or later operating system I typically consider 60 seconds or less from startup to desktop being available to be a normal boot time. Machines with Windows 8/UEFI/SSD should be faster.

We can see from here

• Win Logon Init took over 3 minutes before Explorer Init started
• Explorer Init consumed 5 minutes
• Post-boot period ran for 90 seconds.

First I wanted to check what is causing delay in this section. To do this I select the time period from start of Winlogon Init up to start of Explorer Init, and hit Ctrl+Shift+. or right click and select Zoom All In New View

I now have a view of just the selected time period

Disk Performance is one of the most popular causes of slow computing, so I drag that in first by expanding Storage -> Disk Usage -> Service Time, by Process, Path Name, Stack and dragging into my view

Sorting by Disk Service Time descending we can see Symantec Anti-Virus is a big hitter with the disk access. A lot of access on files related to Anti-Virus Definitions.

If we add IO Type into the grey column, we can see there is a lot of writes by the Anti-Virus. This is indicative the AV is attempting to perform updates.

Note: When a column is added to the “grey” section it turns into a Group By filter

When we select this , we can see the period this writing is occurring, with the blue selection.

Attempting without Anti-Virus cut 1 minute from our first logon time. However removing Anti-Virus is unlikely to be a permanent solution. Because AV was updating itself, we updated the Anti-Virus package in the operating system deployment.

Upgrading from Symantec Endpoint Protection 12.1.4013.4013 R02 to 12.1.4112.4156 fixed this issue

Sometimes I will also use the Path Tree and Extension settings in Group By to identify activity by file path or particular type of file.

OK but we still have a very long boot time….

Next I typically check for CPU consumption, under Computation –> CPU Usage (Sampled) –> Utilization by Process, Stack

Symantec Popular here

Expanding stacks:

Sysfer.dll = Symantec Application Control

Next I look at Services. In this case I had checked services in Win Logon Init phase, and now had filtered down to the next phase –Explorer Init

We can see WSearch has a long service init time.

When then “zoom all” of this view, and add our storage again. We see MSIEXEC is installing VLC. We can see this ran for almost a whole minute. Replacing VLC MSI with VLC Portable version, took another minute off our first logon.

Finally in a major section of the boot phase we can see Lync busiest on the disk

Upgrading Lync from 15.0.4641.1000 to 15.0.4641.1001 http://support.microsoft.com/kb/2881070

After the fixes:

• Symantec Update
• Changing VLC Installation
• Updating LYNC

We now had a much cleaner logon time – 81 seconds for Win Logon Init & Explorer Init phase. WPR after the fixes: