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 Windows 7 boot/shutdown/hibernate/standby/resume issues

slow Boot bootvis performance

  • Please log in to reply
1220 replies to this topic

#976
doveman

doveman

    Advanced Member

  • Member
  • PipPipPip
  • 391 posts
  • Joined 22-August 05
I've uninstalled Avast (and Sandboxie as I need to reinstall it) and I also disabled something in the BIOS called "SATA IDE Combined Mode" which seems to have fixed the BSOD I was getting when running Plex Media Server. It also installed two new devices/drivers for my IDE ports, so I think before they were somehow connected to the SATA controller and should now be separate.

Anyway, even though my BootPostBootTime has come down from around 80s to 43s, my MainPathBootTime has now doubled from around 22s to 42s, giving a current boot time of around 85s.

I see the ExplorerInit stage now takes about 24s whereas before it was only 3.8s!

The drive enumeration time has come down a bit (4+X+0+0 seems to have disappeared). The SATA drive connected to the AHCI controller still shows as an IDE device here, so I guess that's just a quirk of the report. This is with my IDE DVD connected, I'll try adding my IDE HDD as well next.

<phase name="bootStart" startTime="39" endTime="5926" duration="5887">
<pnpObject name="PCIIDE\IDEChannel\5+1270fc08+0+0" type="Device" activity="Enum"
startTime="1393" endTime="4906" duration="3513" prePendTime="0" description="IDE Channel" friendlyName="ATA Channel 0"/>
<pnpObject name="PCIIDE\IDEChannel\5+1270fc08+0+1" type="Device" activity="Enum"
startTime="1394" endTime="4906" duration="3512" prePendTime="0" description="IDE Channel" friendlyName="ATA Channel 1"/>
<pnpObject name="PCIIDE\IDEChannel\4+223a9b9c+0+1" type="Device" activity="Enum"
startTime="253" endTime="1267" duration="1014" prePendTime="0" description="IDE Channel" friendlyName="ATA Channel 1"/>
<pnpObject name="IDE\DiskSAMSUNG_HD103SJ_________________________1AJ10001\5+2ba897a2+0+0.0.0" type="Device" activity="Start"
startTime="4933" endTime="5877" duration="944" prePendTime="944" description="Disk drive" friendlyName="SAMSUNG HD103SJ ATA Device"/>

TVService and MPExtended still show a Total time of around 4.5s each but that's something I'll have to put up with unless the authors can reduce it somehow.

I tried looking at the Disk Graph but didn't really understand it and couldn't see the Queue Depth, so I'm not sure if that's improved or not.

ETL at https://docs.google....dit?usp=sharing

Attached Files




How to remove advertisement from MSFN

#977
MagicAndre1981

MagicAndre1981

    after Windows 7 GA still Vista lover :)

  • Patrons
  • 6,092 posts
  • Joined 28-August 05
  • OS:Vista Ultimate x86
  • Country: Country Flag

Donator

have you run the optimization? Changing an AV tool is a huge change and now you should train Windows a bit.
Posted Image

#978
doveman

doveman

    Advanced Member

  • Member
  • PipPipPip
  • 391 posts
  • Joined 22-August 05

have you run the optimization? Changing an AV tool is a huge change and now you should train Windows a bit.


OK, I'll try that, if I can get the NIC working again that is as it's decided to go funny and says there's no network cable connected. I had the same problem before whenever I had my CF Card IDE adapter connected but I've tried disconnecting any IDE devices and it's still not working, so I might need to get yet another flippin motherboard :angry:

#979
schmohawk

schmohawk
  • Member
  • 4 posts
  • Joined 07-July 13
  • OS:Windows 7 x64
  • Country: Country Flag
Hi, I've been reading through this thread after having run

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

with what I thought was success... At least, I didn't have any errors in the process, until I ran the first xperf trace on the ETL file, and got the annoying and cryptic message:

applying restriction of access for trace processing
113409 Events were lost in this trace.  Data may be unreliable.
This is usually caused by insufficient disk bandwidth for ETW logging.
Please try increasing the minimum and maximum number of buffers and/or
the buffer size.  Doubling these values would be a good first attempt.
Please note, though, that this action increases the amount of memory
reserved for ETW buffers, increasing memory pressure on your scenario.
See "xperf -help start" for the associated command line options.

I tried adding the various switches to the line (-BufferSize 512 -MinBuffers 128 -MaxBuffers 1024), etc. but nothing made a difference, I'd always get the same error.

The ETL is only 25 MB, and I've uploaded it to Dropbox should you have a chance to look at it. I'd sure like to get past the xperf issue, though. My hard drive is a 1.5TB decent Hitachi, with several partitions, but there's lots of empty space. And I have 8GB of RAM and a pagefile that is also 8GB.

I did run ProcMon and turn on boot logging for another go round, but I couldn't see what to do with all the 18 pml files it created, adding up to 4.5GB!

Any and all suggestions welcome.

Thanks,

Here's the link to my boot_BASE+CSWITCH+POWER_1.etl

#980
MagicAndre1981

MagicAndre1981

    after Windows 7 GA still Vista lover :)

  • Patrons
  • 6,092 posts
  • Joined 28-August 05
  • OS:Vista Ultimate x86
  • Country: Country Flag

Donator

my last post is gone (for what ever reason).


The trace is corrupted/incomplete and you should run a new boot trace.
Posted Image

#981
schmohawk

schmohawk
  • Member
  • 4 posts
  • Joined 07-July 13
  • OS:Windows 7 x64
  • Country: Country Flag

my last post is gone (for what ever reason).


The trace is corrupted/incomplete and you should run a new boot trace.


I ran a new boot trace with xbootmgr, and the file came out to be 200MB, better than before, but still, I cannot run xperf on it, and when I open it in Performance Analyzer, it warns that over 43,000 events are missing.

Errr... wait... looking backwards in the posts today, I see that mine is gone, too... dang! So here goes... rewriting...

Between the time of my first post and this morning when you responded, I discovered the new Win Performance Toolkit 5.0. Using the new Windows Performance Recorder, I ran a successful round of 3 On/Off: Boot Traces, and opened the resulting ETL files in the new Windows Performance Analyzer. I took screenshots of two graphs that I thought are most helpful, they are below. Then I went ahead and ran the "xperf /tti" command against one of the 3 ETL files, and I have attached the summary.xml. It seems like it extracted the right results, so for boot traces, I will just use the new tool from now on. I'd like to find out if the new Recorder tool can also do the Prefetch/ReadyBoot defrag cycle...

One more thing, I just discovered a page in German where someone described how to actually fix the buffers/memory issue. Page is at http://www.wintotal....-wieder-munter/ and basically he says to change the regkey HKLM\SYSTEM\CurrentControlSet\Control\WMI\Autologger\ReadyBoot\MaxFileSize from 20 (decimal) to 60 (decimal), and a couple other useful things I hadn't known about... so after all this, maybe I will give xbootmgr one more try at tracing.

This is the Boot Phases graph:
Posted Image

... and this is a mocked up shot of the Lifetime by Process graph, well, a thumbnail bcuz it's too obnoxious & large an image to just embed.
Posted Image


Thank you for any suggestions you can provide as to what I can do to better my boot time. When I started working on this last week, Restart time was 133 seconds, so it's down to about 68, pretty good already!

>>>>8 hours later... OK... I have changed the buffer/memory settings and this is what fixed my issues with losing events and with not being able to run the xperf analysis of the xbootmgr etl files. It was so simple!

So, I have run a completely new boot trace, and attached the summary xml file. As of this update, I am deleting the previously mentioned version, and am including the latest one which came from the successful run of xperf.

It looks like my there two major slowdowns on my system: Avira and Windows Search... I'm considering dumping the built in search if I can find a good alternative that includes content searches (maybe dnGrep...) but not sure what I can do about Avira, as I'm a beta tester for tehm and can't (won't) use another AV.

Thanks,

Attached Files


Edited by schmohawk, 11 July 2013 - 07:33 AM.


#982
MagicAndre1981

MagicAndre1981

    after Windows 7 GA still Vista lover :)

  • Patrons
  • 6,092 posts
  • Joined 28-August 05
  • OS:Vista Ultimate x86
  • Country: Country Flag

Donator

WinLogonInit is a bit slow.

I need the ETL file to see some details.
Posted Image

#983
schmohawk

schmohawk
  • Member
  • 4 posts
  • Joined 07-July 13
  • OS:Windows 7 x64
  • Country: Country Flag
OK, I've uploaded the ETL here: https://docs.google....dit?usp=sharing

#984
MagicAndre1981

MagicAndre1981

    after Windows 7 GA still Vista lover :)

  • Patrons
  • 6,092 posts
  • Joined 28-August 05
  • OS:Vista Ultimate x86
  • Country: Country Flag

Donator

your Disk is busy during boot. Reduce the IO load, to speed boot up.

Also entering the password at logon (RequestCredentials) causes a delay of 11s:

ZDZQoBB.png
Posted Image

#985
doveman

doveman

    Advanced Member

  • Member
  • PipPipPip
  • 391 posts
  • Joined 22-August 05

have you run the optimization? Changing an AV tool is a huge change and now you should train Windows a bit.

 

Thanks. Doing that reduced it from 61s to 40s :)

 

I've disabled most of my boot apps and don't even have an AV or Firewall installed at the moment whilst I debug some issues, so it will increase once I re-add those but hopefully I can keep it down to something reasonable (originally it was something like 266s with all the apps loading!).



#986
doveman

doveman

    Advanced Member

  • Member
  • PipPipPip
  • 391 posts
  • Joined 22-August 05

Is it safe to use

 

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

 

for shutdown tracing or do we need to leave DRIVERS out, as we do for boot tracing to avoid BSODs?



#987
MagicAndre1981

MagicAndre1981

    after Windows 7 GA still Vista lover :)

  • Patrons
  • 6,092 posts
  • Joined 28-August 05
  • OS:Vista Ultimate x86
  • Country: Country Flag

Donator

I can't remember that I ever got a BSOD at shutdown.
Posted Image

#988
doveman

doveman

    Advanced Member

  • Member
  • PipPipPip
  • 391 posts
  • Joined 22-August 05

I can't remember that I ever got a BSOD at shutdown.

OK, thanks. I've got a backup just in case anyway ;)



#989
doveman

doveman

    Advanced Member

  • Member
  • PipPipPip
  • 391 posts
  • Joined 22-August 05

Hmm, my boot time has crept up again, to 108s, then 112s and now down to 85s, whereas it was as low as 44s before.

 

I've changed the SATA ODD cable and the IDE HDD cable as they turned out to be dodgy and put the PCI tuner card back in but otherwise I don't think I've changed anything.

 

I'm not seeing any troublesome durations on the storage devices like there were before.

 

The only degradation issues listed in the logs are

 

This application took longer than usual to start up, resulting in a performance degradation in the system startup process:
     File Name  : lpuninstall.exe
     Friendly Name  : LastPass Installer
     Version  : 2.0.20
     Total Time  : 7177ms
     Degradation Time : 2177ms
     Incident Time (UTC) : ‎2013‎-‎07‎-‎16T16:06:17.749600400Z

 

This application took longer than usual to start up, resulting in a performance degradation in the system startup process:
     File Name  : svchost.exe
     Friendly Name  : Host Process for Windows Services
     Version  : 6.1.7600.16385 (win7_rtm.090713-1255)
     Total Time  : 6450ms
     Degradation Time : 1450ms
     Incident Time (UTC) : ‎2013‎-‎07‎-‎16T16:06:17.749600400Z

 

which don't explain the increase.

 

etl uploaded to https://docs.google....dit?usp=sharing

 

 



#990
MagicAndre1981

MagicAndre1981

    after Windows 7 GA still Vista lover :)

  • Patrons
  • 6,092 posts
  • Joined 28-August 05
  • OS:Vista Ultimate x86
  • Country: Country Flag

Donator

the TVservice starts slowly.

Most of the delay is caused by all tools you run at startup (47s):

<interval name="PostExplorerPeriod" startTime="39836" endTime="86536" duration="46700">
And again your HDD is busy during boot which is the bottleneck for you.
Posted Image

#991
doveman

doveman

    Advanced Member

  • Member
  • PipPipPip
  • 391 posts
  • Joined 22-August 05

Thanks. That TVService causes a shutdown delay as well, as although it closes quickly, within 2s, it doesn't seem to tell Windows that it's closed and so Windows waits 12s or so before continuing. They're looking at that, I'll have to ask if anything can be done about the startup as well but probably not as the tuner card has to initialise, etc.

 

Strangely though, on my next boot it was back down to 43s! I don't actually have much loading at startup at all, just the bare minimum and have left most stuff to be started as needed by the user. I probably will re-enable some things that really should be started automatically but I want to make sure the baseline is stable first.

 

Compared to the boot you analysed and my last boot it shows

MainPathBootTime  38563 vs 18469

BootPostBootTime 46700 vs 23500

 

I'll have to keep an eye on it for a few days and see if it behaves.



#992
kevin79

kevin79

    Newbie

  • Member
  • 11 posts
  • Joined 10-May 11
  • OS:Windows 7 x64
  • Country: Country Flag

I'm having issues with my boot (and resume from hibernate) speeds. Will you please take a look and see if anything shows why? I've looked at the trace but it doesn't make sense to me.

 

https://docs.google....dit?usp=sharing - The zip contains the cab, etl and xml files.

 

The machine is a Lenovo ThinkPad T420 with Windows 7 Enterprise SP1 64bit. It also has 8GB of RAM, an Intel i5 running at 2.30GHz.



#993
MagicAndre1981

MagicAndre1981

    after Windows 7 GA still Vista lover :)

  • Patrons
  • 6,092 posts
  • Joined 28-August 05
  • OS:Vista Ultimate x86
  • Country: Country Flag

Donator

first, your prefetcher is completey ruined:

Attached File  readyBoot.png   4.62KB   1 downloads

next the HDD is busy all the time:

Attached File  disk.png   117.94KB   1 downloads

The disk queue is 75, which is bad.


Also some servies are extremely slow to satrt:

vmware-usbarbitrator (totalTransitionTimeDelta="98527"), vmware-converter (totalTransitionTimeDelta="13997"), VMwareHostd" (totalTransitionTimeDelta="14044").


Install the Enterprise Hotfix Rollup:

http://www.msfn.org/...rtup/?p=1034088

reduce the number of startet services and programs you load (you can start VMware service for expample later via a cmd, that's what I do) and run the optimization, I linked in the first post.


See if this improves boot perfromance.
Posted Image

#994
doveman

doveman

    Advanced Member

  • Member
  • PipPipPip
  • 391 posts
  • Joined 22-August 05

I found this article about measuring Disk Latency.https://blogs.techne...Redirected=true

 

I don't really understand it all but I did try looking at the Counters in Performance Monitor but it didn't really mean much to me.

 

I guess what I really need is a way to monitor the latency / IO which also shows what activity is happening, which also logs it as it's almost impossible to catch things in real-time when everything is constantly changing.



#995
MagicAndre1981

MagicAndre1981

    after Windows 7 GA still Vista lover :)

  • Patrons
  • 6,092 posts
  • Joined 28-August 05
  • OS:Vista Ultimate x86
  • Country: Country Flag

Donator

the Resource Monitor shows the disk queue:

post-70718-0-77963900-1374168816.jpg

http://www.techrepub...ge-performance/

Attached Files


Edited by MagicAndre1981, 18 July 2013 - 11:34 AM.

Posted Image

#996
xs32

xs32
  • Member
  • 2 posts
  • Joined 18-July 13
  • OS:Windows 7 x64
  • Country: Country Flag

Hi MagicAndre - great thread.

 

For the last 6 months, I've been experiencing the following issue at Windows 7 SP1 64bit Enterprise shutdown:
- shutdown works fine when done within a couple hours of startup
- shutdown takes forever (until ACPI? timeout and forced reboot) if the PC has been on for longer than that.

I have captured a good shutdown and a bad shutdown file (etl) with BASE+CSWITCH+DRIVERS+POWER and loaded them up in the GUI but can't make much sense of the information. I think I need your expert help!

 

This was the command I used (from the first post) xbootmgr -trace shutdown -noPrepReboot -traceFlags BASE+CSWITCH+DRIVERS+POWER -resultPath C:\TEMP
Good and bad shutdowns are here:

https://www.dropbox....rm9s/hVIwM_tK6c

Let me know what you think

Thanks



#997
schmohawk

schmohawk
  • Member
  • 4 posts
  • Joined 07-July 13
  • OS:Windows 7 x64
  • Country: Country Flag

your Disk is busy during boot. Reduce the IO load, to speed boot up.

Also entering the password at logon (RequestCredentials) causes a delay of 11s:

ZDZQoBB.png

 

I wasn't sure if this response was directed towards me or not. . . . this was my ETL file:  https://docs.google....dit?usp=sharing

 

Thanks,



#998
MagicAndre1981

MagicAndre1981

    after Windows 7 GA still Vista lover :)

  • Patrons
  • 6,092 posts
  • Joined 28-August 05
  • OS:Vista Ultimate x86
  • Country: Country Flag

Donator

@xs32

 

the plug & play service hangs for you. This causes the delay. But I have no idea how to fix this.

 

 

@schmohawk

 

yes, I was talking to you.


Posted Image

#999
xs32

xs32
  • Member
  • 2 posts
  • Joined 18-July 13
  • OS:Windows 7 x64
  • Country: Country Flag

Thanks MagicAndre. That's a step in the right direction. I'll do some more research and maybe unplug a couple USB devices i don't use on a regular basis to see if it helps.



#1000
kevin79

kevin79

    Newbie

  • Member
  • 11 posts
  • Joined 10-May 11
  • OS:Windows 7 x64
  • Country: Country Flag

I stopped those services from starting automatically and ran the optimization process but it still didn't seem to help. Here is a new boot trace. Any ideas?

 

https://docs.google....dit?usp=sharing







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

1 user(s) are reading this topic

0 members, 1 guests, 0 anonymous users