Jump to content

Here's a Real Mystery - Something Chewing Up CPU After Bootup


NoelC

Recommended Posts

I don't reboot very often, maybe once or twice a month.

 

Over the past couple of months I've noticed that after reboots my Win 8.1 x64 MCE system runs one thread and does more or less continuous but low-rate I/O for some minutes (e.g. 15 or 20 minutes, after which it stops).  I noticed it again after Windows Update dropped its load this week.

 

Today I did some reboots to try to diagnose this.

 

The process that's running is System, and it's using up one of the 24 logical processors (i.e., it shows a continuous roughly 4.2% CPU usage).  After, say, 15 or 20 minutes of doing this the System CPU usage just drops suddenly to near-zero (e.g., 0.01%) and the system runs normally thereafter.

 

During the time System is running that thread I can't start such things as CHKDSK and System Restore.  They just hang, then they proceed when whatever System is doing finally ends.

 

I've watched the Resource Monitor and the System process accesses the master file table of my system volume or backup drive (i.e., G:\$Mft),.  I also saw it occasionally write to C:\Windows\System32\config\SOFTWARE.LOG1.  But those may be coincidence - it's not consistently showing any disk or network access, even though the I/O is constant, so I suspect whatever I/O activity it is doing may be something like IOCtl calls.  To do what, I don't know.

 

  • My system is otherwise well-tuned and stable, and free of malware (verified with MalwareBytes Anti Malware), and I actually feel no significant impact from this - other than if I'd like to do a System Restore or something right after reboot I can't until it finishes.
     
  • Nothing is logged in the System Event Log that gives any clue as to what it's doing or why it should be doing this.
     
  • SFC /VERIFYONLY reports everything's healthy.

Could it be Windows Defender doing some kind of after-boot scan (though I'd expect that to busy MsMpEng, not System)?  On my list of things to do is to disable Defender and see what changes.

 

This activity by the System process shows increasing I/O rates up to a point where it peaks, then it drops to zero and starts up again.  Some of the increases are gradual and some quicker.  Check out this oddball pattern of the thread's I/O rate, from Process Hacker:

 

IORate.png

 

It's clearly following an algorithm of some sort, and not random, as it does finally finish.  Maybe some kind of cache compaction or...  ???

 

My next step will be to set up the Windows Performance Recorder to see if it will shed more light on exactly what's being done.

 

Any other suggestions?

 

-Noel

Link to comment
Share on other sites


4.2% CPU really isn't much. I am not sure why you are worried about it.

My guess is that it maybe finishing system startup and preparing any services (which may run later)

 

Just because you can see the desktop doesn't mean the system is completely booted.

Link to comment
Share on other sites

4.2% CPU really isn't much. I am not sure why you are worried about it.

My guess is that it maybe finishing system startup and preparing any services (which may run later)

 

Just because you can see the desktop doesn't mean the system is completely booted.

 

Thing is, I don't know if it's typical, and I do like to know why things happen.  This only started relatively recently.

 

And though the 4% isn't missed, the inability to do certain things for 20 minutes after bootup is definitely not something I want to live with if I don't have to.

 

I have captured an .etl file, now on to analysis...

 

Edit:  Early analysis results:  Looks like the system is validating all its volume snapshots... 

 

Specifically, the ntoskrnl.exe!KiStartSystemThread going through volsnap.sys!VspOpenFilesAndValidateSnapshots, boiling down to low level I/O control calls.

 

StartupCPUAnalysis.png

 

Now what I need to figure out is why this activity became [more] noticeable / intrusive not too long ago. 

 

-Noel

Edited by NoelC
Link to comment
Share on other sites

Hi Andre, thanks for your interest.  You have infinitely more experience analyzing these traces than I do, and I'd be grateful if you'd look over the data to see what you think.  I'd rather not make it public, but I'll be happy to send it to you personally...  Watch for a PM...

 

Bootup isn't something I pay much attention to since I do it infrequently.

 

FYI, I have my volume snapshot space set to 50 GB.

 

Edit:  I finally figured out what I did that caused this process to stretch out like it has: 

 

Late last year I increased the space available for volume snapshots on my external backup drive up to some 900 GB.  Thus it has been dutifully accumulating snapshots due to my nightly backups.  On looking just now I see that I have over 2 months worth (e.g., 60+ snapshots) available.  Thus, the process that the system normally goes through at startup validating volume snapshots quietly has gone from just a few minutes to tens of minutes because of the sheer additional volume of snapshots.

 

Now that I know that the system does this, and the downside, I'm happy to know that it's normal activity.  For what it's worth I've just reconfigured to be a bit more conservative.  I really don't need the ability to do a restore from any snapshot in the last 2+ months.  Just a few weeks is enough.

 

-Noel

Edited by NoelC
Link to comment
Share on other sites

  • 2 weeks later...

Create an account or sign in to comment

You need to be a member in order to leave a comment

Create an account

Sign up for a new account in our community. It's easy!

Register a new account

Sign in

Already have an account? Sign in here.

Sign In Now
  • Recently Browsing   0 members

    • No registered users viewing this page.
×
×
  • Create New...