Saturday, July 16, 2016

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.

Sunday, July 10, 2016

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!

Saturday, July 18, 2015

A Spectrum of Mass Storage Performance

Every time I get a new computer or external drive, I run disk performance tests.  Whether the results elate or depress me, I forget the details within a week.  (Well, at least until I got my first SSD, which I don't think I'll ever forget.)

I just installed a new Samsung 850 Evo SSD (mSATA) in my desktop rig, and I decided to do things differently this time.  I not only ran performance tests on the new drive, but also on various machines and drives I've had for some time.  Having learned a few things along the way, I've decided to publish the results.  That will compensate for my dodgy memory and maybe help someone out who wants to know something about performance.

The tests were run using iometer 1.1.0.  I only included my three Windows machines because I use them most often.  If I run any tests on my MacBook Air or Chromebook in the future, I will publish them, too.

The performance of each drive was measured with four tests: 4k random read, 4k random write, 256k sequential read, 256k sequential write.  All tests were run with a queue depth of 32.

The three machines on which I ran tests are summarized in the following table.

Table 1: Machines Tested
Computer NameCPUChipsetOS
Dell Inspiron 660Core i5-3340B75 Express (Intel 7 Series/C216)Windows 8.1 x64
Acer Aspire 4830TGCore i5-2430MHM65 Express (Intel 6 Series/C200)Windows 7 x64
HP Stream 13Celeron N2840Integrated (Pentium N and J series)Windows 8.1 x64

Before you head elsewhere on the Internet because these machines range from pedestrian to lame, understand that drive performance is largely independent of the processor and increasingly of the chipset.

The following table states the test results.

Table 2: Test Results
MachineDrive4k random read (IOPS)4k random write (IOPS)256k sequential read (MBPS)256k sequential write (MBPS)
Dell 660Seagate Barracuda 1 TB SATA III (boot)374.45311.18127.95127.7
Dell 660MyBook 3.0 1 TB USB172.1295.4172.4572.55
Dell 660SanDisk Extreme USB 64 GB26871372134.79211.71
Dell 660WD Caviar 2500JS 250 GB SATA II in Cable Matters UAS dock84.07188.3815.3930.31
Dell 660Samsung 850 Evo mSATA 500 GB via Crucial USB adapter42097622218.16235.58
Dell 660Samsung 850 Evo mSATA 500 GB in Cable Matters UAS dock3362135783450.55438.11
Dell 660Samsung 850 Evo mSATA 500 GB (boot)9748286242504.77505.92
Dell 660Seagate Barracuda 1 TB SATA III in Cable Matters UAS dock136.2252.81130.81130.59
Dell 660Seagate Barracuda 1 TB SATA III376.550.85130.8130.33
Acer 4830TGCrucial M500 480 GB mSATA (boot)8346359315304.69411.75
Acer 4830TGSanDisk Extreme USB 64 GB2020862132.06107.44
HP Stream 13Samsung MBG4GC 32 GB eMMC (boot)6129120092.0440.63
HP Stream 13SanDisk Extreme USB 64 GB25291372132.99189.66

OK, that's a lot of data to ingest. Some graphs might help, but providing some analysis is better still.

SSD is fast.  Even using a slower physical interface (SATA instead of PCIe) and a slower software interface (AHCI instead of NVMe) than the fastest available, SSD provides almost 30 times the IOPS of my fastest mechanical drive with almost 4 times the throughput.  The throughput is nice when I move large video files around, but the IOPS substantially improve my moment-to-moment computer use as a programmer.

Especially when using SSD, the hardware used to bridge to USB matters.  There are two tests of the Samsung SSD attached to the Dell 660 via USB.  One uses an adapter I got from Crucial when I installed an SSD in the Acer, the other a Cable Matters dock I bought to read 3.5" drives I have from older machines.  The dock uses an ASM1053E chip, which supports the UAS protocol.  It gets double the throughput and 3-4 times the IOPS compared to the (older) Crucial adapter.  I don't know how much of that difference is UAS as opposed to better USB or SATA throughput within the chip, but keep in mind when you buy a dock, enclosure or adapter cable that the chip makes a difference.

USB storage is faster on Windows 8.1 than Windows 7.  The SanDisk thumb drive is the only disk I tested on all three machines.  The performance on the two Windows 8.1 machines is impressively similar, considering the difference in compute power between the two.  Meanwhile, the Windows 7 machine lags on all tests except read throughput.  Although I attribute the difference to the OS, I will have to admit that the Windows 7 machine is the oldest, running a Sandy Bridge processor and corresponding chipset.  There is the possibility that the silicon in that machine is inferior.

For mechanical disks, fragmentation matters.  There are three tests of the Seagate Barracuda in the Dell 660.  The test results for that disk as the boot disk are different from the results for that disk attached via USB and attached via SATA but not the boot drive.  Between that first test and the other two, I defragmented the drive.  That increased the throughput for both of the later tests.  Strangely, it also killed random write performance.

Despite poor throughput, eMMC drives provide a good user experience.  OK, the tests alone don't establish this, at least the user experience part.  The throughput is bad.  Not as bad as the old WD Caviar I connected via USB, but the worst thing I tested otherwise.  However, in a machine running Windows 8.1 in just 2 GB of RAM (and a Bay Trail Celeron CPU), the user experience is surprisingly good.  I attribute it to the IOPS.  In 2 GB of RAM, Windows is going to page.  A lot.  The extra IOPS reduce the perceived lag, especially compared to other budget notebooks you can find at Best Buy or Staples running slow mechanical drives.

Tuesday, February 4, 2014

Making Peace With Comcast Triple Play

I have finally given in.  After years of refusing to sign up for a Comcast Triple Play package, I have consumed the Kool Aid.  And I have to admit, I am happy, but it took a while to get here.

My objection to the Triple Play is Comcast Voice, or more specifically, the loss of control over my equipment as a Voice customer.  I first got internet from Comcast July 3, 1998 (at a then life-changing download speed of 256 kbps).  I quickly understood the economics of renting a cable modem from Comcast and bought my own.  I have upgraded several times and worked through several routers as well over the years.  Besides saving money, it is nice to control my own upgrade destiny.

A few days after signing up for my new package, I received the "wireless gateway" that Comcast wanted me to use, a Technicolor TC8305C.  Technicolor?  Really?  Not even Arris?  I confirmed through Comcast that the device supports DOCSIS 3.0, but was immediately disappointed to see that it does not support IPv6.  Powering up the unit and connecting to a laptop only worried me further.  Only a 2.4 MHz radio, no guest network and very limited firewall configuration.  It was also unclear whether the DHCP server supported address reservation.

Oh well, I figured, I'll just disable the router and use the device as a telephony modem.  No such luck.  The bridge mode cannot be enabled by the user.  Several people reported on Comcast forums or DSL Reports having problems getting Comcast support to enable bridge mode, and that the modem left bridge mode after being power cycled.

Based on posts indicating that Comcast allowed customers to own telephony devices, I ordered an Arris TM822G through Amazon.  I took the Technicolor device to my local Comcast office and told them I was going to use my own modem.  I was told that, unlike the cable modem, my Comcast franchise did not allow consumers to purchase and use their own telephony device.  After some discussion about the inadequacies of the router in the device, the service rep brought out an assortment of telephony modems that Comcast rented.  The only one that was DOCSIS 3.0 was a Ubee DVM3203B.  Ubee?  I thought Technicolor was bad.

My options having run out (other than dropping the Triple Play before even activating it), I took the modem home.  I spent a little under an hour trying to activate it at comcast.com/activate.  The DNS server Comcast configured did not even resolve comcast.com.  Yikes!  I tried IP addresses and using curl or telnet to connect, but had no success.

Calling 1-855-OK-BEGIN connected me to a young woman who was confident we'd be up and running in ten minutes.  Let me assure you, it was more like thirty minutes.  Things started out smoothly, with me reading MAC numbers off the modem and us running through power cycling the modem.  Multiple times the modem light sequence never got to the expected state.  When we finally got the lights the way they were supposed to be, my phone had no dial tone and my computer could not get initialized via DHCP.  The young woman did something to "activate" the phone line, and one last power cycle got me both a dial tone and an internet connection that allowed me to browse.

Before I forget: I had to wade through many posts with incorrect information before I found that the username/password to access the cable modem status (at the standard 192.168.100.1) is admin/cableroot.  I was reassured to see that all eight download channels and three of four upload channels were active.

With that done, I expected to swap in my router for my laptop, power cycle the router, and be up and running.  No such luck.  Only after multiple power cycles of both the modem and the router did the router finally get an IP address.  It was a 50.x.x.x instead of the 71.x.x.x that I had had for years, but who cares about the public IP address when you are finally up and running again.

Well, up and running is an overstatement.  Browsing felt like I was working on an old dial-up modem.  I had trouble even connecting to speedtest.net, and when I did I got 0.3 Mbps download, while the upload test never finished.  I checked the modem status and the signals were all good.  Download powers were between 2 and 5 dBmV, with SNR over 40 dB.

I power cycled everything again.  This time my WAN IP address was back to its old 71.x.x.x, but speedtest readings were still horrible.  I kept running about every minute while trying to figure out what could be wrong.  Finally, about twenty minutes later, speedtest results were back to about 58 Mbps download and 11 Mbps upload, just what they were before the equipment change.  I don't know whether the slowness was coincidental or the result of changing the modem, but I was happy to have my old performance back.

It's about a month later, and the modem has worked without problems, both internet and voice.  My WAN IP address switched back to 50.x.x.x soon after the first day, which caused a couple of problems with work connections where IP addresses are white listed, but those issues were quickly resolved.

Wednesday, April 11, 2012

Reviving Twonky Media on WD My Book Live

I have a 2 TB WD My Book Live NAS drive for storage of backups and media. I love that I can write to it faster (about 45 MB/s using robocopy) than a local USB 2.0 external drive (under 30 MB/s). However, I have loathed the device, too, since the music, video and pictures I stored on it were not showing up in DLNA client software (e.g. my PS3, NetGear MP-101, Macs and PCs). The server was visible to all, but it appeared to have no media files to serve.

I confirmed the basics of the configuration multiple times. Twonky Media was enabled. Each share was flagged as sharing all media file types. I restarted the service, rebuilt the database, rescanned the device. Nothing changed. After googling, I discovered I could connect to the NAS box with ssh. There were many recommendations to do this, rename two files, then restart Twonky Media. I did so with no change in behavior. However, after a little digging, I discovered a problem with the Twonky Media configuration. Once I changed that, everything started working.

The steps I followed were:

Login to the MyBook Live at http://mybooklive/UI/login
Enable SSH at http://mybooklive/UI/ssh
Connect via ssh (username = root, password = welc0me)
cd /CacheVolume/twonkymedia
vi twonkymedia-server.ini
change contentbase=/ to contentbase=/shares
save and exit
restart twonky at http://mybooklive:9000/config under Maintenance

Depending on your network, browser and ssh client, you may need to use a numeric IP address rather than "mybooklive". If you use Windows and don't have an ssh client, I recommend putty, which is what I used.

Sunday, April 3, 2011

Why Is Flash Still Hogging My CPU?

Flash has had hardware acceleration "forever", or at least as long as I can remember. I suppose it did not back when it was always called Shockwave Flash, but in those days there probably was not much hardware acceleration to take advantage of.

The purpose of hardware acceleration is to allow Flash to do its job while using less CPU, instead letting the GPU hardware do some of the work. On a computer with a slower CPU, this may be the difference between getting smooth video or something closer to a choppy sequence of poor quality still photos. For more modern computers, this should allow the machine to produce smooth, high quality video while allowing the CPU to work on other things.

Flash 10.1 upped the ante by adding hardware decoding, which means the work of decompressing highly compressed video formats like H.264 could be performed by GPUs with this capability built in. The 10.2 iteration of Flash introduced Stage Video, which "helps websites deliver best-in-class video across screens and browsers by enabling access to hardware acceleration of the entire video pipeline."

After upgrading to Flash 10.2, I was left asking "why is Flash still hogging my CPU?" Watching March Madness On Demand from my old-but-serviceable everyday desktop (Athlon 64 X2 3800+, Windows XP SP3, GeForce 8400GS graphics), for example, pinned the CPU between 90 and 100%. Other video sites like ABC and Hulu ran at about 50% CPU, effectively monopolizing one of the two CPU cores.

I wondered whether I needed to upgrade to a newer, but still entry level, video card like a 220, 240, 430 or 440, or whether the DirectX 9 limitation of Windows XP was a problem. However, when I checked out Stage Video on Adobe's site, I ran the examples and found that 720p video scaled to full screen could run at under 15% CPU. The Big Buck Bunny demo is especially cool, as it allows you to turn Stage Video on and off to compare CPU usage.

After a little thought, my suspicion is that sites like ABC and Hulu use Flash plug-ins or other code that prevents the Stage Video pipeline from working, probably to implement digital rights management (DRM). Maybe the problems are related to the way in which the videos are encoded or streamed. In any case, other sites for which this seems to be true include Crackle, The WB, PBS and CBS.

Tuesday, February 1, 2011

Flash At Last For My Archos 32

I got an Archos 32 Internet Tablet for Christmas.  It is not really a tablet; I call it my Android Touch because its form factor and primary usage profile are similar to the iPod Touch.  My objective was to have an Android device to verify the functionality of apps I develop  The specs are reasonable for the price and Archos released a firmware upgrade in December that included Froyo, also known as Android 2.2.  I have to admit, though, that I was jealous of my son for whom I bought an Archos 70, which has a truly beautiful multi-touch screen.

The downside of having a non-phone device is that it is not Google certified and out of the box does not have Google apps such as Gmail, YouTube, and most importantly, the app Market.  I finally got around to finding a way around this and was successful enough to have Flash 10.1 running within minutes.

The magic is gapps4archos.apk.  A link for downloading it is in the forums on archosfans.com.  Because the forum post specifically talks about firmware 2.0.54 and I had already upgraded to 2.1.04, I did not have high hopes that the app would work.  Regardless, I downloaded the file to my PC. After turning off application debugging via USB on my Archos 32, I connected the USB cable between it and the PC. The Archos showed up as the E: drive in Windows. I copied the downloaded file from the PC to E:, ejected the E: drive in Windows, then unplugged the device from USB. I opened the Files app on the Archos home screen, found the file gapps4archos and tapped it. (Note that my device's application settings allow apps from unknown sources.)  In the app, I clicked the button to install Google apps. When that was done, I rebooted the Archos (held the power button down, choose Power Off, then Reboot). When it came back up the home screen had Gmail, YouTube, the app Market, and others.

I first ran Gmail, entered my Google account information, and was soon synchronizing data and settings between the Archos and Google. I then started the Market app, searched for "Adobe Flash" in the market, and chose to download Flash 10.1.  When that download was done I started the Browser app and went to addictinggames.com.  Success.  To test Flash video streaming, I went to crackle.com and was watching a trailer with just a few taps.  I was able to rotate to landscape orientation and push the Flash player to full screen mode.  OK, on a 3.2" screen, it was not an amazing cinematic experience, but it was extremely gratifying nonetheless.