通过

Windows Enterprise Client Boot and Logon Optimization – Part 7, ReadyBoot Analysis

  • 项目

This post continues the series that started here.

In my last post, I proposed that the troubleshooting approach for boot and logon performance is to identify long running boot phases and then to investigate activities that occur during and across those phases.

ReadyBoot is an activity that occurs across multiple phases on systems with rotational disks.

Recap

Part 4 of this series introduced ReadyBoot and I provided a method for extracting ReadyBoot statistics from a boot trace. To revisit -

We can extract ReadyBoot information with

xperf -i <filename.etl> -o ReadyBootSummary.txt -a bootprefetch -summary

The output is simple text and so we choose an output file with a .txt extension. Once collected, the output looks like

image_thumb2

As mentioned in the graphic, you should aim for Prefetch-Hit Ratio and Request-Hit Ratio to exceed 80%.

This data already provides us with an indication of whether there are problems with ReadyBoot.

Event Log

The Windows Event Log also contains some information about the state of ReadyBoot. Specifically, whether the boot plan was correctly calculated. To see this, navigate to

Event Viewer –> Application and Services Logs –> Microsoft –> Windows –> ReadyBoost –> Operational

The ReadyBoost (not a typo) Operational log writes an event 1016 every time the boot plan is calculated. When this occurs after boot, the 1016 should be logged with a Reason of System Boot Completion and a Result of 0x0 -

image

You may see a Reason other than System Boot Completion but these events do not represent the boot plan calculation done at boot time.

In cases where the Result is not 0x0, there was an error calculating the boot plan.

Windows Performance Analyzer (WPA)

Any analysis trace captured on a rotational disk system running Windows 7 or later includes ReadyBoot events. Opening this trace with WPA provides a ReadyBoot graph under the Storage category.

It’s possible an error or some manual intervention prevents ReadyBoot from running. Typically, this occurs when the SuperFetch service is disabled and the following registry value is set to 0x5, causing Windows to assume the system boots from SSD. 0x0 also disables pre-fetching, while 0x3 is the default and recommended value.

HKLM\SYSTEM\CurrentControlSet\services\rdyboost\Parameters\ReadyBootPlanAge

I like to view the graph and manipulate the table at the same time so I open two instances (see Part 5 for WPA usage) -

  • First ReadyBoot graph instance – display as graph only
  • Second ReadyBoot graph instance – display as table only

image

This screen shot shows my preferred column ordering which I’ve achieved by dragging column headers. Columns that were not visible were added by right-clicking a column header and adding the column of interest. Lastly, I clicked the Size column heading to sort by size.

This view shows me that 137 MB of read-hit data came from the C:\Trend Micro folder during boot.

This example comes from a very old Windows 7 trace where this behaviour was quite common across all antivirus products – i.e. loading massive virus definition files during boot (which places a lot of I/O pressure on the system). To my knowledge, all antivirus vendors have take steps to improve on this behaviour and a lot less antivirus data is pre-fetched during boot in the latest version of most products.

Remediation

The information I’ve provided in this post probably suggests some actions you can take when ReadyBoot has issues but let me spell them out for you -

  • There’s no ReadyBoot data in your trace
    • First, make sure your system has a rotational drive and not an SSD
    • If your system has a rotational drive, ensure that HKLM\SYSTEM\CurrentControlSet\services\rdyboost\Parameters\ReadyBootPlanAge has a value of 0x3 and that the SuperFetch service is running with a start-up type of Automatic
  • ReadyBoot Prefetch-Hit Ratio and Request-Hit Ratio are lower than 80%
    • Check the disk speed of the system. If it’s a 5400 RPM drive in a system with one or more fast CPUs, pre-fetched data may be processed too quickly for the ReadyBoot driver to keep up with demand. It may not be possible to improve ReadyBoot efficiency
    • Examine the data being read during boot using the ReadyBoot table as I’ve outlined above. Consider whether there are components that add large volumes of data to the boot and logon process that might be removed or changed to a leaner version. Keep in mind the volume of data pre-fetched for a brand new installation of Windows 8.1 is 315 MB so components that compare to or exceed this number are of interest
    • Optimize ReadyBoot as discussed in Part 4 of this blog post series
  • Event Log 1016 contains a Result code other than 0x0
    • Optimize ReadyBoot as discussed in Part 4 of this blog post series

Note that in some cases, I’ve observed the need to delete the contents of %windir%\Prefetch and to run the ReadyBoot optimization again. Deleting the contents of the prefetch folder is often discouraged but the act of manual ReadyBoot optimization rebuilds it for you.

As I’ve mentioned a few times now, ReadyBoot still has limitations. There’s only so much that may be done to account for poor Disk I/O and reading large volumes of data during boot and logon. Ideally, new systems will use SSDs for their OS disk and you keep the boot and logon process as lean as possible.

If an SSD is out of the question, steer clear of 5400 RPM disks and ensure the OS disk on systems you deploy to your Enterprise are at least 7200 RPM.

Conclusion

We’ve discussed the analysis and remediation of ReadyBoot which is the first cross-phase activity you need to consider during boot and logon performance analysis.

Next Up

Code Integrity Checking

Comments

  • Anonymous
    August 05, 2015
    The comment has been removed
  • Anonymous
    August 11, 2015
    This post concludes the series that started here . Over the past few weeks I’ve presented a “lite” version
  • Anonymous
    November 14, 2017
    The boot trace recorded that my PC has 713 MB total with 465 MB of "Miss event", 247 MB of "Hit event", while I see your Miss is really low. Is it a big problem for me and what is the Miss event?
    • Anonymous
      November 14, 2017
      The comment has been removed
      • Anonymous
        November 15, 2017
        The comment has been removed
        • Anonymous
          November 16, 2017
          In my experience, AV software often has this sort of impact. It tends to have impact on the boot process in all sorts of ways. Thinking about in generally, each binary the system loads in order to boot is probably being scanned in some way.A 5400 rpm drive with 4MB of RAM is problematic too. Obviously I haven't seen the trace but it's really likely that what you are prefetching isn't enough to feed demand from the processor and behind that, the disk is too slow to feed the readyboot cache.
          • Anonymous
            November 16, 2017
            So is there any way to fix it instead of removing Avast? I have a post on answer.microsoft and get lots of suggestions to do that and use Microsoft Security Essential but I still have problem with it. In fact, I try to boot with Avast is disabled but the boot is still slow. I'm not sure if my data can cause that. Two years ago I had another Windows 7 on my laptop (other partition) to investigate more, and silly, this Windows 7 boots fast even with Avast installed. I have a post here: https://forum.avast.com/index.php?topic=207705.0 , if it doesn't bother you, I hope you can take a little time to see the video how slow my boot is and if possible, I hope you give me something to contact. Thank you!
            • Anonymous
              November 16, 2017
              If you upload the WPT trace to OneDrive and share with markrenoden@outlook.com, I'll take a look and see if anything jumps out.