wuauserv High CPU Usage Revisited

Wow, I thought wuauserv was bad a week ago when it ran for almost two hours. Today it ran for over two hours fifteen minutes.

2016-07-16 13:47:25:145  376 c08 AU Launched new AU client for directive 'Download Approval', session id = 0x1
2016-07-16 14:18:00:884  376 c08 AU Successfully wrote event for AU health state:0
2016-07-16 16:03:17:531  376 128c Agent   * Added update {87F7FA52-8F77-4D3B-A873-F651F9DF9946}.100 to search result

Oh, and here's what "high CPU usage" looks like:

I traced it's activity using Process Monitor from sysinternals. It spent a lot of time repeatedly checking some registry keys, such as HKLM\SYSTEM\Setup\SystemSetupInProgress. It also wrote to C:\Windows\SoftwareDistribution\DataStore\DataStore.edb, which is over 1 GB in size, and read OBJECTS.DATA and INDEX.BTR in C:\Windows\System32\wbem\Repository. Googling DataStore.edb led me to C:\Windows\System32\esentutl.exe and it's /d option to defragment. So, I tried

C:\Windows\System32\esentutl.exe /d C:\Windows\SoftwareDistribution\DataStore\DataStore.edb

It did not change the size of the file significantly, but I'll see whether it changes the execution time in the future.

wuauserv High CPU Usage

I'm not a Windows fanboy. I'm also not a Windows hater. But there are things I hate about Windows. The registry is one of those. Another is Windows Update. I have a Windows 7 notebook that's four and a half years old. From time to time, Windows Update eats CPU for almost two consecutive hours. According to Resource Monitor, there's no disk or network I/O, just one pinned CPU core. Resource Monitor shows 25% CPU for services.exe in the Processes section. The Services section fingers wuauserv.exe as the culprit. The log at C:\Windows\WindowsUpdate.log shows things starting out pretty normally when I booted my machine.

2016-07-10 12:03:35:614  560 14d8 Misc ===========  Logging initialized (build: 7.6.7601.19161, tz: -0400)  ===========
2016-07-10 12:03:35:614  560 14d8 Misc   = Process: C:\Windows\system32\svchost.exe
2016-07-10 12:03:35:614  560 14d8 Misc   = Module: c:\windows\system32\wuaueng.dll
2016-07-10 12:03:35:598  560 14d8 Service *************
2016-07-10 12:03:35:614  560 14d8 Service ** START **  Service: Service startup
2016-07-10 12:03:35:614  560 14d8 Service *********
2016-07-10 12:03:36:035  560 14d8 Agent   * WU client version 7.6.7601.19161
2016-07-10 12:03:36:051  560 14d8 Agent   * Base directory: C:\Windows\SoftwareDistribution
2016-07-10 12:03:36:051  560 14d8 Agent   * Access type: No proxy
2016-07-10 12:03:36:144  560 14d8 Agent   * Network state: Connected
2016-07-10 12:03:36:503  560 1640 Report CWERReporter::Init succeeded
2016-07-10 12:03:36:503  560 1640 Agent ***********  Agent: Initializing Windows Update Agent  ***********
2016-07-10 12:03:36:519  560 1640 Agent   * Prerequisite roots succeeded.
2016-07-10 12:03:36:519  560 1640 Agent ***********  Agent: Initializing global settings cache  ***********
2016-07-10 12:03:36:519  560 1640 Agent   * WSUS server: 
2016-07-10 12:03:36:519  560 1640 Agent   * WSUS status server: 
2016-07-10 12:03:36:519  560 1640 Agent   * Target group: (Unassigned Computers)
2016-07-10 12:03:36:519  560 1640 Agent   * Windows Update access disabled: No
2016-07-10 12:03:36:519  560 1640 DnldMgr Download manager restoring 0 downloads
2016-07-10 12:03:36:534 2440 bc8 Misc ===========  Logging initialized (build: 7.6.7601.19161, tz: -0400)  ===========
2016-07-10 12:03:36:534 2440 bc8 Misc   = Process: c:\Program Files\Microsoft Security Client\MpCmdRun.exe
2016-07-10 12:03:36:534 2440 bc8 Misc   = Module: C:\Windows\system32\wuapi.dll
2016-07-10 12:03:36:534 2440 bc8 COMAPI -------------
2016-07-10 12:03:36:534 2440 bc8 COMAPI -- START --  COMAPI: Search [ClientId = Microsoft Security Essentials (EDB4FA23-53B8-4AFA-8C5D-99752CCA7094)]
2016-07-10 12:03:36:534 2440 bc8 COMAPI ---------
2016-07-10 12:03:36:550 2440 bc8 COMAPI <<-- --="" 0x00000080:="" 12:03:39:389="" 12:03:41:355="" 12:03:42:104="" 12:03:42:119="" 12:04:05:828="" 14d8="" 1a74="" 2016-07-10="" 4830tg="" 560="" agent:="" agent="" allerid="Microsoft" bios="" brand="Acer" c:="" comapi:="" computer="" criteria="(IsInstalled = 0 and IsHidden = 0 and CategoryIDs contains '6b9e8b26-8f50-44b9-94c6-7846084383ec' and CategoryIDs contains 'e0789628-ce08-4437-be74-2495b842f43b')" data="" date="2011-06-08T00:00:00" download="" dwprovflags="" essentials="" finding="" for="" id="1033" ignore="" indows="" initializing="" lientid="Microsoft" locale="" microsoft="" misc="" model="Aspire" na="" name="InsydeH2O" oftwaredistribution="" online="Yes;" os="" party="" pre="" priority="No" product="" release="" report:="" report="" reporting="" revision="V1.05" scope="{Machine}" search="" security="" service="" serviceid="{7971F918-A847-4430-9279-4A52D1EFE18D}" signature="" signed:="" start="" static="" submitted="" third="" tmp="" type="0x00000003" updates="" uredir="" v1.05="" validating="" version="" with="" wuredir.cab="">

Shortly after that, automatic update started logging.

2016-07-10 12:04:21:413  560 14d8 AU ###########  AU: Initializing Automatic Updates  ###########
2016-07-10 12:04:21:413  560 14d8 AU AU setting next detection timeout to 2016-07-10 16:04:21
2016-07-10 12:04:21:413  560 14d8 AU AU setting next sqm report timeout to 2016-07-10 16:04:21
2016-07-10 12:04:21:413  560 14d8 AU   # Approval type: Pre-download notify (User preference)
2016-07-10 12:04:21:459  560 14d8 AU Successfully wrote event for AU health state:0
2016-07-10 12:04:21:459  560 14d8 AU Initializing featured updates
2016-07-10 12:04:21:459  560 14d8 AU Found 0 cached featured updates
2016-07-10 12:04:21:459  560 14d8 AU Successfully wrote event for AU health state:0
2016-07-10 12:04:21:459  560 14d8 AU AU setting pending client directive to 'Download Approval'
2016-07-10 12:04:21:459  560 14d8 AU Successfully wrote event for AU health state:0
2016-07-10 12:04:21:459  560 14d8 AU AU finished delayed initialization
2016-07-10 12:04:21:459  560 14d8 AU AU setting next sqm report timeout to 2016-07-11 16:04:21
2016-07-10 12:04:21:459  560 14d8 AU #############
2016-07-10 12:04:21:459  560 14d8 AU ## START ##  AU: Search for updates
2016-07-10 12:04:21:459  560 14d8 AU #########

Within less than a minute, there's a nearly six minute gap in the logging, which is not so bad, but then there's an hour and fifty minutes. Yikes! That's the time during which a CPU core was pinned.

2016-07-10 12:05:15:981  560 1a74 DtaStor WARNING: Attempted to add URL http://download.windowsupdate.com/c/msdownload/update/software/secu/2016/05/ie11-windows6.1-kb3160005-x64_bbf479a874758fd4e921c3f07dc16bb9674831d3.msu for file u/R5qHR1j9TpIcPwfcFruWdIMdM= when file has not been previously added to the datastore
2016-07-10 12:11:06:236  560 1824 DtaStor Default service for AU is {7971F918-A847-4430-9279-4A52D1EFE18D}
2016-07-10 12:11:06:236  560 1824 Agent AddTargetedServiceMapping: 943D2D57-4E1B-478E-9807-F25A2BF809C1 -> 7971F918-A847-4430-9279-4A52D1EFE18D
2016-07-10 12:11:06:252  560 1824 Agent WARNING: could not delete Software\Microsoft\Windows\CurrentVersion\WindowsUpdate\Services\943d2d57-4e1b-478e-9807-f25a2bf809c1 service registry key 0x80070002
2016-07-10 12:11:06:252  560 1824 Agent WARNING: Failed to delete service from the backup store, error = 0x80070002
2016-07-10 12:11:06:252  560 1824 Agent RemoveTargetedServiceMapping: 943D2D57-4E1B-478E-9807-F25A2BF809C1 -> 7971F918-A847-4430-9279-4A52D1EFE18D
2016-07-10 14:01:07:037  560 1a74 Agent   * Added update {87F7FA52-8F77-4D3B-A873-F651F9DF9946}.100 to search result
2016-07-10 14:01:07:037  560 1a74 Agent   * Added update {94FDBC91-8954-4F4F-B82F-44B02752D74A}.205 to search result

I am not the only one having problems. There are several posts on the Internet and various advice that may or may not help. For example, http://superuser.com/questions/821032/svchost-exe-high-memory-usage-wuauserv suggests the following.

net stop wuauserv
net stop bits
rd /s /q %windir%\softwaredistribution
net start bits
net start wuauserv
wuauclt.exe /detectnow

I have not tried that as it seems pretty brute force to wipe out C:\Windows\SoftwareDistribution, under which my machine has 5485 files totaling 1,520,724,188 bytes. What do I do? Generally be patient and use my MacBook Air when my patience runs out!