2

Windows Boot PreSessionInit time up to 140sec. Struggling to find reason.

OS Name:                   Microsoft Windows 8.1 Pro
OS Version:                6.3.9600 N/A Build 9600
Processor(s):              1 Processor(s) Installed.
                           [01]: Intel64 Family 6 Model 58 Stepping 9 GenuineInt
el ~2101 Mhz
BIOS Version:              Insyde Corp. R0093C6, 8/22/2012
Available Physical Memory: 1,296 MB
Virtual Memory: Max Size:  21,478 MB
Virtual Memory: Available: 9,341 MB
Virtual Memory: In Use:    12,137 MB

followed this guide: Newish Windows 10 installation taking ~ 20 minutes in the pre session init phase

what I found is:

interval endTime="130463" startTime="0" name="PreSMSS" duration="130463"

however I could not find any driver that cause such a lag.

etl link: https://mega.nz/#!pmpByQ6D!SouVWRGd3tJQfLMO3XMmiJJBFf3OG5CrMKOqzmPP5-I

it seems like smth loops/waits after bootstart and before systemstart, but it lacks an information what exactly. (I don`t know how to profile it or find here in logs)

(any advise or a link for a tutorial will be much appreciated. Thanks.)

-<pnp>


-<phase endTime="811" startTime="59" name="bootStart" duration="752">

<pnpObject type="Driver" endTime="504" startTime="370" name="\Driver\kl1" duration="134" prePendTime="134" activity="Init"/>

<pnpObject type="Device" endTime="192" startTime="119" name="ACPI\PNP0A08\0" duration="74" prePendTime="74" activity="Enum" friendlyName="" description="PCI Express Root Complex"/>

<pnpObject type="Device" endTime="565" startTime="522" name="PCI\VEN_8086+DEV_282A+SUBSYS_90A5104D+REV_04\3+11583659+0+FA" duration="43" prePendTime="43" activity="Start" friendlyName="" description="Intel(R) Mobile Express Chipset SATA RAID Controller"/>

<pnpObject type="Device" endTime="319" startTime="291" name="PCI\VEN_8086+DEV_1E16+SUBSYS_90A5104D+REV_C4\3+11583659+0+E3" duration="29" prePendTime="29" activity="Start" friendlyName="" description="Intel(R) 7 Series/C216 Chipset Family PCI Express Root Port 4 - 1E16"/>

<pnpObject type="Device" endTime="257" startTime="228" name="PCI\VEN_8086+DEV_1E10+SUBSYS_90A5104D+REV_C4\3+11583659+0+E0" duration="29" prePendTime="29" activity="Start" friendlyName="" description="Intel(R) 7 Series/C216 Chipset Family PCI Express Root Port 1 - 1E10"/>

<pnpObject type="Device" endTime="351" startTime="323" name="PCI\VEN_8086+DEV_1E1C+SUBSYS_90A5104D+REV_C4\3+11583659+0+E6" duration="28" prePendTime="28" activity="Start" friendlyName="" description="Intel(R) 7 Series/C216 Chipset Family PCI Express Root Port 7 - 1E1C"/>

<pnpObject type="Device" endTime="288" startTime="262" name="PCI\VEN_8086+DEV_1E12+SUBSYS_90A5104D+REV_C4\3+11583659+0+E1" duration="27" prePendTime="27" activity="Start" friendlyName="" description="Intel(R) 7 Series/C216 Chipset Family PCI Express Root Port 2 - 1E12"/>

<pnpObject type="Device" endTime="96" startTime="73" name="ACPI_HAL\PNP0C08\0" duration="23" prePendTime="23" activity="Start" friendlyName="" description="Microsoft ACPI-Compliant System"/>

</phase>


-<phase endTime="130452" startTime="130159" name="systemStart" duration="293">

<pnpObject type="Driver" endTime="130258" startTime="130190" name="KLIF" duration="67" prePendTime="67" activity="Load"/>

<pnpObject type="unknown" endTime="130258" startTime="130206" name="\REGISTRY\MACHINE\SYSTEM\ControlSet001\Services\KLIF" duration="52" prePendTime="52" activity="unknown"/>

<pnpObject type="Driver" endTime="130316" startTime="130273" name="BasicRender" duration="43" prePendTime="43" activity="Load"/>

<pnpObject type="unknown" endTime="130316" startTime="130277" name="\REGISTRY\MACHINE\SYSTEM\ControlSet001\Services\BasicRender" duration="39" prePendTime="39" activity="unknown"/>

<pnpObject type="Driver" endTime="130316" startTime="130277" name="dlkmd" duration="39" prePendTime="39" activity="Load"/>

<pnpObject type="Driver" endTime="130316" startTime="130277" name="DXGKrnl" duration="39" prePendTime="39" activity="Load"/>

<pnpObject type="unknown" endTime="130316" startTime="130282" name="\REGISTRY\MACHINE\SYSTEM\ControlSet001\Services\DLKMD" duration="33" prePendTime="33" activity="unknown"/>

<pnpObject type="Driver" endTime="130316" startTime="130283" name="DXGKrnl" duration="33" prePendTime="33" activity="Load"/>

<pnpObject type="Driver" endTime="130452" startTime="130438" name="ahcache" duration="14" prePendTime="14" activity="Load"/>

<pnpObject type="Driver" endTime="130173" startTime="130160" name="klhk" duration="13" prePendTime="13" activity="Load"/>

<pnpObject type="Driver" endTime="130190" startTime="130180" name="klbackupflt" duration="11" prePendTime="11" activity="Load"/>

<pnpObject type="unknown" endTime="130452" startTime="130442" name="\REGISTRY\MACHINE\SYSTEM\ControlSet001\Services\ahcache" duration="10" prePendTime="10" activity="unknown"/>

<pnpObject type="Driver" endTime="130337" startTime="130327" name="tdx" duration="10" prePendTime="10" activity="Load"/>

</phase>


-<phase endTime="-1" startTime="130452" name="remainder" duration="-1">

<pnpObject type="Device" endTime="134089" startTime="132745" name="PCI\VEN_10EC+DEV_5209+SUBSYS_90A5104D+REV_01\4+2baf440c+0+00E1" duration="1344" prePendTime="1344" activity="Enum" friendlyName="" description="Realtek PCIE CardReader"/>

<pnpObject type="Device" endTime="132672" startTime="132268" name="ACPI\SNYA006\4+9952f73+0" duration="404" prePendTime="0" activity="Start" friendlyName="" description="Synaptics SMBus ClickPad"/>

<pnpObject type="Driver" endTime="131315" startTime="130940" name="i8042prt" duration="375" prePendTime="375" activity="Load"/>

<pnpObject type="Device" endTime="134729" startTime="134415" name="USB\VID_2109+PID_2813\5+c173ee4+0+2" duration="314" prePendTime="314" activity="Start" friendlyName="" description="Generic USB Hub"/>

<pnpObject type="Device" endTime="135393" startTime="135088" name="USB\VID_8087+PID_0024\5+27e71cae+0+1" duration="305" prePendTime="305" activity="Start" friendlyName="" description="Generic USB Hub"/>

<pnpObject type="Device" endTime="135088" startTime="134783" name="USB\VID_8087+PID_0024\5+17ed8b27+0+1" duration="305" prePendTime="305" activity="Start" friendlyName="" description="Generic USB Hub"/>

<pnpObject type="Device" endTime="136300" startTime="135997" name="USB\VID_05E3+PID_0608\7+18170aa1+0+3" duration="304" prePendTime="304" activity="Start" friendlyName="" description="Generic USB Hub"/>

<pnpObject type="Device" endTime="135713" startTime="135411" name="USB\VID_1A40+PID_0201\6+2df9aaad+0+1" duration="302" prePendTime="302" activity="Start" friendlyName="" description="Generic USB Hub"/>

<pnpObject type="Driver" endTime="131623" startTime="131332" name="SynTP" duration="292" prePendTime="292" activity="Load"/>

<pnpObject type="unknown" endTime="131623" startTime="131359" name="\REGISTRY\MACHINE\SYSTEM\ControlSet001\Services\SynTP" duration="265" prePendTime="265" activity="unknown"/>

<pnpObject type="Driver" endTime="130853" startTime="130606" name="vwifibus" duration="246" prePendTime="246" activity="Load"/>

<pnpObject type="Device" endTime="135968" startTime="135725" name="USB\VID_08FF+PID_168F\6+28e163e5+0+1" duration="244" prePendTime="244" activity="Start" friendlyName="" description="AuthenTec Inc. AES1660"/>

<pnpObject type="Device" endTime="134359" startTime="134206" name="HDAUDIO\FUNC_01+VEN_10EC+DEV_0275+SUBSYS_104D6600+REV_1000\4+3b6b84d4+0+0001" duration="152" prePendTime="0" activity="Start" friendlyName="" description="Realtek High Definition Audio"/>

<pnpObject type="Device" endTime="132280" startTime="132143" name="PCI\VEN_8086+DEV_1E20+SUBSYS_90A5104D+REV_04\3+11583659+0+D8" duration="138" prePendTime="0" activity="Start" friendlyName="" description="High Definition Audio Controller"/>

<pnpObject type="Device" endTime="132254" startTime="132143" name="PCI\VEN_8086+DEV_088E+SUBSYS_40608086+REV_24\4+1c17e3ac+0+00E0" duration="111" prePendTime="29" activity="Start" friendlyName="Intel(R) Centrino(R) Advanced-N 6235" description="Intel(R) Centrino(R) Advanced-N 6235"/>

<pnpObject type="Device" endTime="134198" startTime="134093" name="USB\ROOT_HUB30\4+5999dd8+0+0" duration="105" prePendTime="105" activity="Start" friendlyName="" description="USB Root Hub (xHCI)"/>

<pnpObject type="Device" endTime="132264" startTime="132172" name="PCI\VEN_10EC+DEV_5209+SUBSYS_90A5104D+REV_01\4+2baf440c+0+00E1" duration="92" prePendTime="0" activity="Start" friendlyName="" description="Realtek PCIE CardReader"/>

<pnpObject type="Device" endTime="132247" startTime="132172" name="PCI\VEN_10EC+DEV_8168+SUBSYS_90A5104D+REV_07\4+2519d1f+0+00E3" duration="75" prePendTime="33" activity="Start" friendlyName="Realtek PCIe GbE Family Controller" description="Realtek PCIe GbE Family Controller"/>

<pnpObject type="Driver" endTime="141245" startTime="141179" name="luafv" duration="66" prePendTime="66" activity="Load"/>

<pnpObject type="Driver" endTime="144862" startTime="144797" name="hcmon" duration="65" prePendTime="65" activity="Load"/>

<pnpObject type="unknown" endTime="144862" startTime="144800" name="\REGISTRY\MACHINE\SYSTEM\ControlSet001\Services\hcmon" duration="62" prePendTime="62" activity="unknown"/>

<pnpObject type="Device" endTime="146882" startTime="146820" name="USB\ROOT_HUB20\4+18c659bc+0" duration="62" prePendTime="62" activity="Enum" friendlyName="" description="USB Root Hub"/>

<pnpObject type="unknown" endTime="141245" startTime="141184" name="\REGISTRY\MACHINE\SYSTEM\ControlSet001\Services\luafv" duration="62" prePendTime="62" activity="unknown"/>

<pnpObject type="Device" endTime="132265" startTime="132205" name="PCI\VEN_8086+DEV_1E26+SUBSYS_90A5104D+REV_04\3+11583659+0+E8" duration="60" prePendTime="60" activity="Start" friendlyName="" description="Intel(R) 7 Series/C216 Chipset Family USB Enhanced Host Controller - 1E26"/>

<pnpObject type="Device" endTime="132095" startTime="132046" name="PCI\VEN_8086+DEV_1E31+SUBSYS_90A5104D+REV_04\3+11583659+0+A0" duration="50" prePendTime="0" activity="Start" friendlyName="Intel(R) USB 3.0 eXtensible Host Controller - 0100 (Microsoft)" description="USB xHCI Compliant Host Controller"/>

<pnpObject type="Device" endTime="132128" startTime="132083" name="PCI\VEN_8086+DEV_1E2D+SUBSYS_90A5104D+REV_04\3+11583659+0+D0" duration="45" prePendTime="45" activity="Start" friendlyName="" description="Intel(R) 7 Series/C216 Chipset Family USB Enhanced Host Controller - 1E2D"/>

<pnpObject type="Driver" endTime="132732" startTime="132689" name="IntcAzAudAddService" duration="43" prePendTime="43" activity="Load"/>

<pnpObject type="Device" endTime="132046" startTime="132004" name="PCI\VEN_8086+DEV_0166+SUBSYS_90A5104D+REV_09\3+11583659+0+10" duration="42" prePendTime="42" activity="Start" friendlyName="" description="Intel(R) HD Graphics 4000"/>

<pnpObject type="Device" endTime="132083" startTime="132046" name="PCI\VEN_8086+DEV_1E3A+SUBSYS_90A5104D+REV_04\3+11583659+0+B0" duration="37" prePendTime="37" activity="Start" friendlyName="" description="Intel(R) Management Engine Interface "/>

<pnpObject type="Device" endTime="146820" startTime="146784" name="USB\VID_05CA+PID_18C6\6+28e163e5+0+3" duration="36" prePendTime="36" activity="Enum" friendlyName="" description="USB Composite Device"/>

<pnpObject type="Driver" endTime="130620" startTime="130584" name="fastfat" duration="36" prePendTime="36" activity="Load"/>

<pnpObject type="Driver" endTime="144987" startTime="144953" name="IntelHaxm" duration="34" prePendTime="34" activity="Load"/>

<pnpObject type="Device" endTime="132311" startTime="132280" name="ACPI\GenuineIntel_-_Intel64_Family_6_Model_58_-_______Intel(R)_Core(TM)_i7-3612QM_CPU_@_2.10GHz\_7" duration="31" prePendTime="31" activity="Start" friendlyName="Intel(R) Core(TM) i7-3612QM CPU @ 2.10GHz" description="Intel Processor"/>

<pnpObject type="Driver" endTime="136363" startTime="136334" name="BTHUSB" duration="29" prePendTime="29" activity="Load"/>

<pnpObject type="unknown" endTime="144987" startTime="144958" name="\REGISTRY\MACHINE\SYSTEM\ControlSet001\Services\IntelHaxm" duration="29" prePendTime="29" activity="unknown"/>

<pnpObject type="Driver" endTime="130606" startTime="130578" name="NETwNe64" duration="29" prePendTime="29" activity="Load"/>

<pnpObject type="Driver" endTime="130528" startTime="130501" name="igfx" duration="27" prePendTime="27" activity="Load"/>

<pnpObject type="Device" endTime="134391" startTime="134367" name="SCSI\Disk+Ven_Seagate+Prod_Expansion\000000" duration="24" prePendTime="24" activity="Start" friendlyName="Seagate Expansion SCSI Disk Device" description="Disk drive"/>

<pnpObject type="Driver" endTime="131683" startTime="131660" name="mshidkmdf" duration="23" prePendTime="23" activity="Load"/>

<pnpObject type="Driver" endTime="130892" startTime="130870" name="RTL8168" duration="22" prePendTime="22" activity="Load"/>

<pnpObject type="Driver" endTime="142909" startTime="142887" name="HTTP" duration="21" prePendTime="21" activity="Load"/>

<pnpObject type="Driver" endTime="130924" startTime="130904" name="CmBatt" duration="21" prePendTime="21" activity="Load"/>

<pnpObject type="Driver" endTime="131724" startTime="131705" name="huawei_enumerator" duration="20" prePendTime="20" activity="Load"/>

<pnpObject type="Device" endTime="148158" startTime="148139" name="SWD\WPDBUSENUM\_??_USBSTOR#Disk+Ven_Generic+Prod_Flash_Disk+Rev_8.07#403BCED0+0#{53f56307-b6bf-11d0-94f2-00a0c91efb8b}" duration="18" prePendTime="0" activity="Start" friendlyName="KROTYSOFT_U" description="Flash Disk "/>

<pnpObject type="Driver" endTime="146245" startTime="146227" name="srv2" duration="18" prePendTime="18" activity="Load"/>

<pnpObject type="Driver" endTime="130546" startTime="130529" name="USBXHCI" duration="17" prePendTime="17" activity="Load"/>

<pnpObject type="Driver" endTime="146043" startTime="146026" name="vstor2-mntapi20-shared" duration="17" prePendTime="17" activity="Load"/>

<pnpObject type="Driver" endTime="131332" startTime="131315" name="klkbdflt" duration="17" prePendTime="17" activity="Load"/>

<pnpObject type="Driver" endTime="143118" startTime="143102" name="mrxsmb" duration="16" prePendTime="16" activity="Load"/>

<pnpObject type="Driver" endTime="130940" startTime="130925" name="ICCWDT" duration="14" prePendTime="14" activity="Load"/>

<pnpObject type="Device" endTime="135993" startTime="135979" name="USB\VID_058F+PID_6387\403BCED0" duration="14" prePendTime="14" activity="Start" friendlyName="" description="USB Mass Storage Device"/>

<pnpObject type="Driver" endTime="132687" startTime="132673" name="USBHUB3" duration="14" prePendTime="14" activity="Load"/>

<pnpObject type="Driver" endTime="130868" startTime="130854" name="RSPCIESTOR" duration="14" prePendTime="14" activity="Load"/>

<pnpObject type="Driver" endTime="136334" startTime="136321" name="btmhsf" duration="13" prePendTime="13" activity="Load"/>

<pnpObject type="Device" endTime="134776" startTime="134763" name="USB\VID_17E9+PID_4301+MI_02\7+36ce9476+0+0002" duration="13" prePendTime="13" activity="Start" friendlyName="USB to Audio" description="USB to Audio"/>

<pnpObject type="Driver" endTime="130568" startTime="130556" name="usbehci" duration="12" prePendTime="12" activity="Load"/>

<pnpObject type="Driver" endTime="142632" startTime="142620" name="NativeWifiP" duration="12" prePendTime="12" activity="Load"/>

<pnpObject type="Driver" endTime="145509" startTime="145497" name="PEAUTH" duration="11" prePendTime="11" activity="Load"/>

<pnpObject type="Driver" endTime="148848" startTime="148837" name="RdpVideoMiniport" duration="11" prePendTime="11" activity="Load"/>

<pnpObject type="Driver" endTime="147724" startTime="147713" name="MsLldp" duration="11" prePendTime="11" activity="Load"/>

<pnpObject type="Driver" endTime="131657" startTime="131645" name="SFEP" duration="11" prePendTime="11" activity="Load"/>

<pnpObject type="Driver" endTime="146609" startTime="146598" name="tunnel" duration="11" prePendTime="11" activity="Load"/>

<pnpObject type="Device" endTime="134218" startTime="134207" name="HDAUDIO\FUNC_01+VEN_8086+DEV_2806+SUBSYS_104D6600+REV_1000\4+3b6b84d4+0+0301" duration="11" prePendTime="0" activity="Start" friendlyName="" description="Intel(R) Display Audio"/>

<pnpObject type="Driver" endTime="145477" startTime="145467" name="mrxsmb10" duration="11" prePendTime="11" activity="Load"/>

<pnpObject type="Driver" endTime="130463" startTime="130452" name="WinDriver6" duration="11" prePendTime="11" activity="Load"/>

<pnpObject type="Driver" endTime="132140" startTime="132130" name="usbhub" duration="11" prePendTime="11" activity="Load"/>

<pnpObject type="Driver" endTime="145488" startTime="145478" name="Ndu" duration="10" prePendTime="10" activity="Load"/>

<pnpObject type="Driver" endTime="145713" startTime="145702" name="srvnet" duration="10" prePendTime="10" activity="Load"/>

<pnpObject type="Driver" endTime="131753" startTime="131743" name="rdpbus" duration="10" prePendTime="10" activity="Load"/>

</phase>

</pnp>
Improve this question
1
  • I posted what I saw from the trace.
    – magicandre1981
    Commented Jun 25, 2018 at 15:51

1 Answer 1

Reset to default
0

So in the summary you see that the PreSMSS subphase is slow:

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.

In your case it is not a required device that takes too long, it is an driver that doesn't show up in this summary.

When you open the ETL, drag & drop the CPU usage (Sampled) to the analyze pane:

enter image description here

you see that System Process takes a high CPU usage for 130s at the beginning of the boot.

enter image description here

So you need the analyze the CPU usage of System process. In your case it shows that a Kaspersky Filter driver (klbackupdisk.sys) is involved:

enter image description here

Try to remove Kaspersky. Next I see BitLocker Drive Encryption Driver (fvevol.sys). If you have encrypted the Drive undo this and look if boot is faster.

Improve this answer
11
  • Thank you so much for your answer! I did try to remove Kaspersky KTS19 - and it boots same time. I tried to reinstall to older version KTS18 - same. At this point I am pretty much sure it's something conflicting with bitlocker, but the problem is, that I do not have any drives encrypted, and also I tried to turn off this service with no result, so I am not sure what direction to move next. I`ll post new *.etl later today. Thank you.
    – user23124
    Commented Jun 26, 2018 at 5:58
  • Here is new *.etl file: mega.nz/#!pzwCmazQ!V7oqOYNnDcQr8T-dvKqpKG2af5W1B7na5Q-G7QPiJlI Without Kaspersky. I also tried to disable/put to automatic Bitlocker service, also I tried dism restorehealth and sfc /scannow - everything was good, so fvevol.sys is not corrupted. Also tried to put old version of fvevol.sys into drivers folder, same Boot time. Please advise. Thank you.
    – user23124
    Commented Jun 26, 2018 at 6:59
  • hm, still the same. I remember that large fragmentation of hibernation file could cause hangs at boot and fvevol.sys shows up as high CPU usage. This was a known issue in 2014, so maybe the issue was never solved. Disable the hibernation in Windows, reboot and look if this makes boot faster.
    – magicandre1981
    Commented Jun 26, 2018 at 15:12
  • Thanks, but that was already done ( moreover it`s raid stripe of 2 ssd's and performance is pretty decent, even it's old laptop. Any other clues I can look at? checked eventlog just in case anything abnormal - with no result too.
    – user23124
    Commented Jun 26, 2018 at 17:30
  • I also saw this RAID (SCSI\DISK&VEN_INTEL&PROD_RAID_0_VOLUME\4&31AC9113&0&000100). Does the issue also happen without the RAID? 1 SSD is still fast enough
    – magicandre1981
    Commented Jun 27, 2018 at 17:11

You must log in to answer this question.

Not the answer you're looking for? Browse other questions tagged .