Jump to content

Welcome to MSFN Forum
Register now to gain access to all of our features. Once registered and logged in, you will be able to create topics, post replies to existing threads, give reputation to your fellow members, get your own private messenger, post status updates, manage your profile and so much more. This message will be removed once you have signed in.
Login to Account Create an Account


Photo

Trace why Windows 8 boots, shutsdown or hibernates slowly

bootvis Performance Boot slow

  • Please log in to reply
321 replies to this topic

#1
MagicAndre1981

MagicAndre1981

    after Windows 7 GA still Vista lover :)

  • Patrons
  • 5,761 posts
  • OS:Vista Ultimate x86
  • Country: Country Flag

Donator

cSPmLpE.png

This is an updated tutorial of my Windows 7 here.

To get started you need the Windows Performance Tools Kit. Read here how to install it:

http://www.msfn.org/...howtopic=146919

Now open a command prompt with admin rights and run the following commands:

For boot tracing:

xbootmgr -trace boot -traceFlags BASE+CSWITCH+DRIVERS+POWER -resultPath C:\TEMP

Note, in Windows 8 it is safe to use the DRIVERS flag, the Windows 7 bug is fixed in Windows 8.


For shutdown tracing:

xbootmgr -trace shutdown -noPrepReboot -traceFlags BASE+CSWITCH+DRIVERS+POWER -resultPath C:\TEMP

For Standby+Resume:

xbootmgr -trace standby -traceFlags BASE+CSWITCH+DRIVERS+POWER -resultPath C:\TEMP

For Hibernate+Resume:

xbootmgr -trace hibernate -traceFlags BASE+CSWITCH+DRIVERS+POWER -resultPath C:\TEMP

replace C:\TEMP with any temp directory on your machine as necessary to store the output files

All of these will shutdown, hibernate, or standby your box, and then reboot to finish tracing. After you login to your PC, the new startscreen is shown and you have to click to the desktop to see countdown timer. Again, wait until the timer finishes. Afetr you did this you should now have some tracing files in C:\TEMP.

Analyses of the boot trace:

To start create a summary xml file, run this command (replace the name with the name of your etl file)



xperf /tti -i boot_BASE+CSWITCH+DRIVERS+POWER_1.etl -o summary_boot.xml -a boot

Now you see this picture.:

Boot_Summary.png

You have too look at the timing node. All time values are in ms.

The value timing bootDoneViaExplorer shows the time, Windows needs to boot to the desktop.

The value bootDoneViaPostBoot is the time (+10s idle detection) which Windows needs to boot completly after finishing all startup applications.
 

During the OSLoader phase (shown in the value osLoaderDuration), the Windows loader binary (Winload.exe) loads essential system drivers that are required to read minimal data from the disk and initializes the system to the point where the Windows kernel can begin execution. When the kernel starts to run, the loader loads into memory the system registry hive and additional drivers that are marked as BOOT_START.

Visual Cues

This phase begins approximately when the BIOS splash and diagnostic screens are cleared and ends approximately when the “Loading Windows” splash screen appears.


those values show you a summary.

The MainPathBoot Phase
 

What Happens in This Phase
During the MainPathBoot phase, most of the operating system work occurs. This phase involves kernel initialization, Plug and Play activity, service start, logon, and Explorer (desktop) initialization. To simplify analysis, we divide the MainPathBoot phase into four subphases, as show in the next picture. Each subphase has unique characteristics and performance vulnerabilities.

Visual Cues

Visually, the MainPathBoot phase begins when the “Starting Windows” splash screen appears and lasts until the desktop appears. If auto-logon is not enabled, the time that elapses while the logon screen is displayed affects the measured boot time in a trace.


Boot_MainPathBoot.png

PreSMSS Subphase


What Happens in This Subphase
The PreSMSS subphase begins when the kernel is invoked. During this subphase, the kernel initializes data structures and components. It also starts the PnP manager, which initializes the BOOT_START drivers that were loaded during the OSLoader phase. When the PnP manager detects a device, it loads and initializes the device’s drivers

Visual Cues
PreSMSS begins approximately when the “Loading Windows” splash screen appears. There are no explicit visual cues for the end of PreSMSS.


So if the time takes too long for you, look inside the <PNP> node which driver is loading too slowly.

SMSSInit Subphase

What Happens in This Subphase
The SMSSInit subphase begins when the kernel passes control to the session manager process (Smss.exe). During this subphase, the system initializes the registry, loads and starts the devices and drivers that are not marked BOOT_START, and starts the subsystem processes. SMSSInit ends when control is passed to Winlogon.exe.

Visual Cues
There are no explicit visual cues for the start of SMSSInit, but the blank screen that appears between the splash screen and the logon screen is part of SMSSInit. It ends before the logon screen appears.

SMSSInit Performance Vulnerabilities
Video drivers are a common source of performance problems in the SMSSInit subphase. The video driver must be initialized first in the system session and then in the user session. Reduction of video driver initialization time leads to a direct wall-clock reduction in boot time.
Initialization in the user session is typically much faster than in the system session because Windows performs common initialization tasks during the system session.


So if the SMSSInit Phase takes too long, try to get an graphic card driver update.

WinLogonInit Subphase
 

What Happens in This Subphase
The WinLogonInit subphase begins when SMSSInit completes and starts Winlogon.exe. During WinLogonInit, the user logon screen appears, the service control manager starts services, and Group Policy scripts run. WinLogonInit ends when the Explorer process starts.

Visual Cues
WinLogonInit begins shortly before the logon screen appears. It ends just before the desktop appears for the first time.

WinLogonInit Performance Vulnerabilities
Many operations occur in parallel during WinLogonInit. On many systems, this subphase is CPU bound and has large I/O demands. Good citizenship from the services that start in this phase is critical for optimized boot times.
Services can declare dependencies or use load order groups to ensure that they start in a specific order. Windows processes load order groups in serial order. Service initialization delays in an early load order group block subsequent load order groups and can possibly block the boot process .


If you have too long WinLogonInit Time, open the etl file and scroll to the service graph and look for a long delay.

Boot_WinLogonInitPhase.png

In this example the service SavService (Sophos Anti-Virus\SavService.exe) is part of the Plug and Play group and causes a delay because the service takes too long to start. Try to get an update for the hanging service or remove the software.

ExplorerInit Subphase
 

What Happens in This Subphase

The ExplorerInit subphase begins when Explorer.exe starts. During ExplorerInit, the system creates the desktop window manager (DWM) process, which initializes the desktop and displays it for the first time.
This phase is CPU intensive
. The initialization of DWM and desktop occurs in the foreground, while in the background the service control manager (SCM) starts services and the memory manager prefetches code and data. On most systems ExplorerInit is CPU bound, and timing issues are likely the result of a simple resource bottleneck.
Visual Cues
ExplorerInit begins just before the desktop appears for the first time. There is no clear visual cue to indicate the end of ExplorerInit.

ExplorerInit Performance Analysis

Applications—such as antivirus programs or application servers—that are created during service start in this or previous phases can consume CPU resources during ExplorerInit. Some services might not be started yet when ExplorerInit is complete.


So if the ExplorerInit phase takes too long, make sure you minimize the services which use a lot of CPU power and make sure your AV Tool doesn't hurt too much. If it doesn't change the tool and try a different.

The PostBoot Phase
 

What Happens in This Phase
The PostBoot phase includes all background activity that occurs after the desktop is ready. The user can interact with the desktop, but the system might still be starting services, tray icons, and application code in the background.
Specifically, Xperf samples the system every 100 ms during the PostBoot phase. If the system is 80-percent or more idle (excluding low-priority CPU and disk activity) at the time of the sample, Xperf considers the system to be “idle” for that 100 ms interval. The phase persists until the system accumulates 10 seconds of idle time.
Note: When you review traces and report timing results, you should subtract the 10 second idle time that accumulated during PostBoot to determine total boot time.


Visual Cues
There are no explicit visual cues for PostBoot. The phase begins after the user’s desktop appears and ends after satisfying the 10-second metric that was explained earlier.

PostBoot Performance Vulnerabilities
During PostBoot, Windows examines the entries in the various Run and RunOnce keys (Run, RunOnce, RunOnceEx, RunServices, and so on) in the registry and the Startup folder in the file system, and then starts the listed applications.


If post boot takes too long, reduce the number of running applications at startup with the help of msconfig.exe or AutoRuns.

if possible, you should always use the new Fast Startup/ hybrid Boot of Windows 8. At the end of this guide you'll learn how to analyze this new mode.

Analyses of the shutdown trace:

The shutdown is divided into this 3 parts:

Shutdown_picture.png

To generate an XML summary of shutdown, use the -a shutdown action with Xperf:
 


xperf /tti -i shutdown_BASE+CSWITCH+DRIVERS+POWER_1.etl -o summary_shutdown.xml -a shutdown

Open the XML and you see this:

Shutdown_Summary.png

It shows you the most relevant data.
 

<timing shutdownTime="23184" servicesShutdownDuration="1513">

The shutdownTime is in this example 23s. Stopping the services takes 1.5s which is fast.

Next you have an entry for all sessions. Starting with Vista, all services run in Session 0 (Session 0 Isolation) and each user gets his one Session (1,2,..,n).
 

sessionShutdown sessionID="1" duration="3321">

shows the time which it takes to stop all applications which the user is running. In this example it takes 3.3seconds.

UserSession Phase
 

What Happens in UserSession
During this phase, the Client/Server Runtime Server Subsystem (Csrss.exe) shuts down all applications that are running in the user session—that is, all applications that have session ID 1.

If after 5 seconds any application blocks shut down, Windows displays the dialog box in Figure 24 so that users can choose to force or cancel shutdown.

Shutdown_cancel.png

UserSession Performance Vulnerabilities

Because Windows serially shuts down applications, any delay in a process’s shutdown path contributes to the total shutdown duration. To ensure a speedy shutdown, every application must respond quickly to shutdown notification messages (WM_QUERYENDSESSION and WM_ENDSESSION).
Windows uses long time-outs so that applications have sufficient time to shut down and save user data. Therefore, applications can have a significant effect on shutdown performance.


sessionShutdown sessionID="0" duration="1513">

The value sessionShutdown sessionID="0" shows the servicesShutdownDuration. So you can see which service takes too long to stop.

SystemSession Phase
 

What Happens in SystemSession

This phase includes two subphases:
• Preshutdown notification. Windows serially shuts down all services that registered to receive preshutdown notifications. Ordered services—services that have set up the shutdown order of dependent services—are shut down before non-ordered services.
• Shutdown notification. All services that registered to receive shutdown notifications are shut down in parallel.

If all services have not exited after 20 seconds (in Windows Vista) or 12 seconds (in Windows 7), the system continues the shutdown. Processes and services that do not shut down in a timely manner are left running as the system shuts down.

SystemSession Performance Vulnerabilities

In the preshutdown notification subphase, the SCM serializes the waits. Therefore, these services block system shutdown until they exit or until the wait hint time-out expires.
Services are not guaranteed to have enough time to finish all their work in the shutdown notification subphase before the system shuts down.


In both cases expand the node and look at the shutdownDuration value.

It helps you to identify a hanging application are service.

KernelShutdown Phase
 

What Happens in KernelShutdown
In the KernelShutdown phase, the rest of the system, including all devices and drivers, is shut down.


To calculate the time spent in KernelShutdown, subtract the time that is required to shut down the system and user sessions from shutdownTime.

In my example:

KernelShutdown = 23184 - 3321 - 1513 = 18350

In this case the 18.35 seconds are very slow. In the <interval> you see an entry ZeroHiberFile which takes too long. In this expample the user enabled the Option ClearPageFileAtShutdown under HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Control\Session Manager\Memory Management to 1. This overrides the hiberbation file with 0 to delete personal data. This causes the huge slowdown. Setting this option to 0 would save 12.64 seconds of shutdown time.

That is all you need to analyze slow shutdown issues.

Analyses of the Hibernation trace::

To generate the XML, run this command:
 

xperf /tti -i hibernate_BASE+CSWITCH+DRIVERS+POWER_1.etl -o summary_hibernation.xml -a suspend

Analyses of the Sleep/Resume trace::



xperf /tti -i standby_BASE+CSWITCH+DRIVERS+POWER_1.etl -o summary_sleep.xml -a suspend

Open the XMLs and look for long BIOS init times and services/application which take very long to suspend and resume.




Windows 8 includes a new boot mode called Fast Startup or Hybrid Boot.

If this boot mode is slow, you have to run this command to trace the slowness:
 


xbootmgr -trace fastStartup -noPrepReboot -traceFlags BASE+CSWITCH+DRIVERS+POWER -resultPath C:\TEMP

I've already explained how this mode works. First Windows shuts down the users, next Windows hibernates the kernel with all drivers and the services. Next the PC shuts down. Now Windows boots again, read the hibernation file and resumes all services and drivers and next you go to the Logon screen.

So we now need to view all 3 actions. So first look is the closing of apps and logging off the users takes too long. Create the shutdown XML with this command:
 


xperf -i fastStartup_BASE+CSWITCH+DRIVERS+POWER_1.etl -o summary_shutdown.xml -a shutdown

Open it and you'll see this:

01_Windows8_fastStartup_Shutdown_XML.png

Note, that the file only shows the logoff of the user sessions. Here check which programs take long to close. The FlushVolume is writing open files/cache to the HDD.

Next, we must look if the hibernation is slowly. To generate the XML run this:
 


xperf -i fastStartup_BASE+CSWITCH+DRIVERS+POWER_1.etl -o summary_hibernation.xml -a suspend

Open it and you'll see this:

02_Windows8_fastStartup_Hibernation_XML.

Now the same applies like Hibernation. Look which services or drivers take a long time to suspend. Also note, that those values are in µs!

If those 2 steps are fine, we must look at the new Startup. To generate the XML run this:
 


xperf -i fastStartup_BASE+CSWITCH+DRIVERS+POWER_1.etl -o summary_Boot.xml -a boot

Open it and you'll see this:

03_Windows8_fastStartup_Boot_XML.png

When you compare it to the normal boot, you see some differences. The PreSMSS and SMSSInit Subphases are gone. This is replaced with SystemResume. If this takes a very long time, open again the summary_hibernation.xml and look for devices are services which take long time to resume.

The rest of the boot is the same like the normal boot. If WinLogonInit are long, check the Group Policies and if you're restoring of network connections. And if PostExplorerPeriod is long, you also start too many desktop programs or your new Windows 8 apps take too long to load the data to show in the live tiles.


I hope, this helps you to fix your Performance issues with Windows 8.

 

 

The pictures Shutdown_cancel.png, Shutdown_picture.png and Boot_MainPathBoot.png were taken from this Windows On/Off Transition Performance Analysis Guide. Read it if you need more information.


Edited by MagicAndre1981, 19 October 2013 - 12:06 PM.



How to remove advertisement from MSFN

#2
aviv00

aviv00

    Windowaizer

  • Members
  • PipPipPipPipPip
  • 968 posts
thx will try it on my laptop got black screen for while duno the reason

#3
MagicAndre1981

MagicAndre1981

    after Windows 7 GA still Vista lover :)

  • Patrons
  • 5,761 posts
  • OS:Vista Ultimate x86
  • Country: Country Flag

Donator

ok. Do you use the new Fast Startup?

#4
aviv00

aviv00

    Windowaizer

  • Members
  • PipPipPipPipPip
  • 968 posts
new ?
duno if its new
but it happened if powercfg h is on and off
so i dont think its relate to fast startup

when it came from from shutdown its boot little faster

Edited by aviv00, 04 September 2012 - 12:15 AM.


#5
Aloha

Aloha

    Advanced Member

  • Members
  • PipPipPip
  • 497 posts
  • OS:none specified
  • Country: Country Flag
Since I installed RTM, it takes longer time to boot into Windows. From the boot menu if I choose RP it logs in normally. But if I choose RTM it seems that the computer resets once before it boots into the Start Screen.

Perhaps I will remove RTM soon.

#6
MagicAndre1981

MagicAndre1981

    after Windows 7 GA still Vista lover :)

  • Patrons
  • 5,761 posts
  • OS:Vista Ultimate x86
  • Country: Country Flag

Donator

@both

upload the traces so that I can take a look at them.

#7
Aloha

Aloha

    Advanced Member

  • Members
  • PipPipPip
  • 497 posts
  • OS:none specified
  • Country: Country Flag
Andre,
There's something I want to make clear first. When I turn on my computer, I see the booting screen and then the boot menu. If I choose RP, the default OS, it boots into the Start Screen quite fast. If I choose RTM, the monitor will turn off then turn on again, and the booting screen will display one more time before I can see the Start Screen. That's why I think it resets before booting.

I disabled Hibernation right after I finished installing W8 RTM. Shut down time is normally quick. So, only boot time is what I care for. I guess if I remove RTM, the problem will be solved.

Now, your tutorial is a little complicated to me. Not sure if I can follow it to the end or not, but I'll try. I'm just afraid I can't post the trace file very soon.

#8
Aloha

Aloha

    Advanced Member

  • Members
  • PipPipPip
  • 497 posts
  • OS:none specified
  • Country: Country Flag
There you are. Hope I did it right.

Edit: delete attachment.

Edited by Aloha, 05 September 2012 - 10:33 AM.


#9
MagicAndre1981

MagicAndre1981

    after Windows 7 GA still Vista lover :)

  • Patrons
  • 5,761 posts
  • OS:Vista Ultimate x86
  • Country: Country Flag

Donator

the boot is fine. 20s to metro or desktop and 30s until everything is loaded.

Activate hibernation again and make a trace of the hybrid boot.

#10
Aloha

Aloha

    Advanced Member

  • Members
  • PipPipPip
  • 497 posts
  • OS:none specified
  • Country: Country Flag
The command promp doesn't allow me to copy and paste. It's a long long long text to type and you ask me to do it again??? I don't intend to use RTM for long, so just a few needed applications were installed on it. There is almost nothing to do there and I hate it if I have to boot into it!

I'll do it tomorrow night and edit this post with the attachment. Bye for now, Andre.

#11
MagicAndre1981

MagicAndre1981

    after Windows 7 GA still Vista lover :)

  • Patrons
  • 5,761 posts
  • OS:Vista Ultimate x86
  • Country: Country Flag

Donator

You can make a rightclick in the CMD and select paste to insert text.

#12
Aloha

Aloha

    Advanced Member

  • Members
  • PipPipPip
  • 497 posts
  • OS:none specified
  • Country: Country Flag
Hi Andre,
I decide to make a new post instead of editing the old one!

Edit: delete attachment.

Edited by Aloha, 06 September 2012 - 08:36 AM.


#13
MagicAndre1981

MagicAndre1981

    after Windows 7 GA still Vista lover :)

  • Patrons
  • 5,761 posts
  • OS:Vista Ultimate x86
  • Country: Country Flag

Donator

you've still used the traditional boot which is ok:

- <timing bootDoneViaExplorer="23828" bootDoneViaPostBoot="37928"

23s to the UI and 28s to be fully booted.

#14
Aloha

Aloha

    Advanced Member

  • Members
  • PipPipPip
  • 497 posts
  • OS:none specified
  • Country: Country Flag
Andre,
Sorry I didn't read the tutorial thoroughly so I posted a wrong file. I'll do it again.

Edited by Aloha, 06 September 2012 - 09:07 AM.


#15
Aloha

Aloha

    Advanced Member

  • Members
  • PipPipPip
  • 497 posts
  • OS:none specified
  • Country: Country Flag
Do you ever read your tutorial again, Andre? It's a huge post and I am scared to read through it!

Here is the trace again. Hope it is the right file this time.

Edit: delete attachment.

Edited by Aloha, 07 September 2012 - 08:31 AM.


#16
MagicAndre1981

MagicAndre1981

    after Windows 7 GA still Vista lover :)

  • Patrons
  • 5,761 posts
  • OS:Vista Ultimate x86
  • Country: Country Flag

Donator

now you use the hybrid boot and it is amazing fast:

resume and go to the UI takes 7s and the Windows is fully running in 9s!

Attached File  Aloha_HybridBoot.png   42.54KB   12 downloads

#17
Aloha

Aloha

    Advanced Member

  • Members
  • PipPipPip
  • 497 posts
  • OS:none specified
  • Country: Country Flag
I don't know why it generated such a strange result. My computer boots slowly in reality, around 1 minute into RTM, and around 40 seconds into RP. Now that you say it's OK, I won't mind it any more.

Okay, it's somewhat interesting to do these traces. Many thanks for all the help. And wish you a nice day, Andre.

#18
Traditore

Traditore

    Newbie

  • Members
  • 12 posts
  • OS:none specified
  • Country: Country Flag
so, i managed to create an xml, my bootDoneViaExplorer is 30sec, and post-boot is 1min. Guess it's too much and I knew that (that's why I'm here). I have an ESET SmartSecurity running but that can't be the problem of 1min booting? Guess I need to look thoroughly. I wonder why MS promises 10sec boot out of the box... I had my 40sec+ boot time right from fresh install.

what I found quickly reviewing is "services autoStartStartTime="16207" autoStartEndTime="37132" autoStartDuration="20925">" services loading for 21 sec. So... disabling system services to speed up? I already have disabled and set to manual some of them according to common sense and BlackViper...

postBootDisturbance="23700" though ALL of auto-start programs are disabled. what else is in this phase?

then again, 16secs before even services to initialize is gross

adding some data, maybe you'll be kind to give some feedback right away, thank you. and thanks for the tutorial.

Posted Image

Edited by Traditore, 11 September 2012 - 10:07 AM.


#19
MagicAndre1981

MagicAndre1981

    after Windows 7 GA still Vista lover :)

  • Patrons
  • 5,761 posts
  • OS:Vista Ultimate x86
  • Country: Country Flag

Donator

give me the ETL file and I'll take a look. Zip it first before uploading.

#20
Traditore

Traditore

    Newbie

  • Members
  • 12 posts
  • OS:none specified
  • Country: Country Flag

give me the ETL file and I'll take a look. Zip it first before uploading.


here. thank you. BootTrace

#21
MagicAndre1981

MagicAndre1981

    after Windows 7 GA still Vista lover :)

  • Patrons
  • 5,761 posts
  • OS:Vista Ultimate x86
  • Country: Country Flag

Donator

boot is terrible broken. The prefetcher doesn't work as it should and your DISK is busy all the time:

Attached File  Win8_disk_IO_prefetcher_broken.png   12.85KB   15 downloads

What I can see is that the NOD32 service takes some CPU time and this causes the slow WinLogonInit phase:

Attached File  Win8_NOD32_service.png   48.02KB   18 downloads

So you should also run the boot optimization I've explained here:

http://www.msfn.org/...howtopic=140262

but it is better to sue the new Hybrid Boot / fast Startup feature of Windows 8:

http://www.msfn.org/...howtopic=152937

#22
Traditore

Traditore

    Newbie

  • Members
  • 12 posts
  • OS:none specified
  • Country: Country Flag

So you should also run the boot optimization I've explained here:

http://www.msfn.org/...howtopic=140262

but it is better to sue the new Hybrid Boot / fast Startup feature of Windows 8:

http://www.msfn.org/...howtopic=152937



1) first I'll try setting NOD service to 'automatic(Delayed)' and see if it helps a bit. I would disable its autorun completely but as I remember it can't be started up via scheduler then, so I really need it autostarting in some way - delayed.

2) I'll do that optimization. Shouldn't I delete prefetch data or something so that OS builds up brand new prefetching?
P.S. Funny thing is that I also have 8Gb ReadyBoost on a flash and I can tell about applications startup faster but no effect on OS boot (if should be any I'm not sure but still...)

3) I don't have hybridBoot option though I'm using leaked final Enterprise OS. What the deal with it?

Thank you for all of your time!

Edited by Traditore, 12 September 2012 - 09:20 AM.


#23
MagicAndre1981

MagicAndre1981

    after Windows 7 GA still Vista lover :)

  • Patrons
  • 5,761 posts
  • OS:Vista Ultimate x86
  • Country: Country Flag

Donator

you must activate hibernation (powercfg -h on) to see the "fast Startup" option in the power settings.

#24
Traditore

Traditore

    Newbie

  • Members
  • 12 posts
  • OS:none specified
  • Country: Country Flag

you must activate hibernation (powercfg -h on) to see the "fast Startup" option in the power settings.


oh, I have that, but I have never seen anything like hybridboot and as you already know my boot sucks...

#25
MagicAndre1981

MagicAndre1981

    after Windows 7 GA still Vista lover :)

  • Patrons
  • 5,761 posts
  • OS:Vista Ultimate x86
  • Country: Country Flag

Donator

In the power saving options you should have an option to select fast startup:

Attached File  fastStartup.png   53.01KB   11 downloads

Now Windows should use the new boot.





Also tagged with one or more of these keywords: bootvis, Performance, Boot, slow

2 user(s) are reading this topic

0 members, 2 guests, 0 anonymous users



How to remove advertisement from MSFN