The case of the Windows Desktop Search CPU hog

My home computer is set up (using MBM 5) to sound off an alarm with the PC Speaker whenever CPU temperature exceeds 70 degrees Celsius. It is not that I overclock it, not at all, but rather because of the embarrassingly poor fan I got with the box (which I didn’t purchase personally) combined with the Pentium 4’s well-known poor thermal characteristics.

The alarm is quite audible and annoying. Fortunately, it is pretty unusual for the CPU to get that hot. I’ve noticed that it does this after more than a few minutes of running at near 100% CPU usage.

Earlier today, I could hear the annoying alarm from across the house. I sat down at the computer and quickly silenced it. Since this isn’t the first time I’ve heard the alarm, I already knew what I was looking for: a CPU hog. More often than not, the culprit is vmware-vmx.exe, VMware Workstation’s virtual machine process. If you run an MS-DOS VM without DOSIDLE or the like, the guest OS hogs the CPU and the blame is placed on vmware-vmx.exe. This can also happen with a modern guest OS like Windows in case the guest is misbehaving for some reason. However, this time, I didn’t remember leaving any VM running on the machine, and indeed, none was to be found.

I opened the Task Manager to examine the situation and after a few moments determined that cidaemon.exe was at 49% CPU usage. This actually means 100% on my system which has a hyper-threaded, single core Pentium 4.

My first reaction was that it’s probably just a random case of a CPU hog since I’ve never experienced it on my system before. Without asking too many questions, I killed the cidaemon.exe process and watched as CPU utilization plummeted to the healthy single-digits.

I got up from the computer and addressed other concerns (washed my car). It was about an hour later that I came back and heard the hectic CPU temperature alarm once again. I took another look at the process list and found out cidaemon.exe has been resurrected, and had returned to avenge its predecessor’s demise with another round of CPU hogging.

At this point I understood there is no recourse but to conduct a deeper investigation. I googled for cidaemon.exe being a CPU hog and pretty much only found the “solution” of disabling Windows Desktop Search. Yeah, well, not so fast. I fired up the debugger and attached to the CPU hogging cidaemon.exe process (there was another instance of cidaemon.exe which was being benign).

The first thing I did is get some basic information on where I found myself:

0:006> lmv m cidaemon
start end module name
01000000 01005000 cidaemon (pdb symbols) C:\WINDOWS\Symbols\exe\cidaemon.pdb
Loaded symbol image file: C:\WINDOWS\SYSTEM32\cidaemon.exe
Image path: C:\WINDOWS\SYSTEM32\cidaemon.exe
Image name: cidaemon.exe
Timestamp: Fri Aug 17 23:56:12 2001 (3B7D84EC)
CheckSum: 00007613
ImageSize: 00005000
File version: 5.1.2600.0
Product version: 5.1.2600.0
File flags: 0 (Mask 3F)
File OS: 40004 NT Win32
File type: 1.0 App
File date: 00000000.00000000
Translations: 0409.04b0
CompanyName: Microsoft Corporation
ProductName: Microsoft® Windows® Operating System
InternalName: cidaemon.exe
OriginalFilename: cidaemon.exe
ProductVersion: 5.1.2600.0
FileVersion: 5.1.2600.0 (xpclient.010817-1148)
FileDescription: Indexing Service filter daemon
LegalCopyright: © Microsoft Corporation. All rights reserved.

OK, so cidaemon.exe is the indexing service’s filter daemon. An educated guess would be that the name is actually short for “content indexing daemon.” I knew that the indexing service is a part of the core Windows XP operating system (as is apparent from the file version of cidaemon.exe above) and not an additional service installed by the separate Windows Desktop Search package I have on my system.

The next thing I did was to see how many threads I am dealing with in this demonic daemon process:

0:003> ~
0 Id: afc.af4 Suspend: 1 Teb: 7ffdf000 Unfrozen
1 Id: afc.a5c Suspend: 1 Teb: 7ffde000 Unfrozen
2 Id: afc.858 Suspend: 1 Teb: 7ffdc000 Unfrozen
. 3 Id: afc.13b4 Suspend: 1 Teb: 7ffdb000 Unfrozen
4 Id: afc.1190 Suspend: 1 Teb: 7ffda000 Unfrozen
6 Id: afc.10d8 Suspend: 1 Teb: 7ffd8000 Unfrozen

OK, looks like I’ve got quite a few. Only the CPU hogging thread is of interest, so let’s check the CPU times, let the process resume for a while, and examine the times once again:

0:003> !runaway
User Mode Time
Thread Time
6:10d8 0 days 0:00:53.515
0:af4 0 days 0:00:00.140
4:1190 0 days 0:00:00.078
3:13b4 0 days 0:00:00.000
2:858 0 days 0:00:00.000
1:a5c 0 days 0:00:00.000
0:003> g
(afc.ca8): Break instruction exception - code 80000003 (first chance)
eax=7ffdd000 ebx=00000001 ecx=00000002 edx=00000003 esi=00000004 edi=00000005
eip=7c901230 esp=0078ffcc ebp=0078fff4 iopl=0 nv up ei pl zr na pe nc
cs=001b ss=0023 ds=0023 es=0023 fs=0038 gs=0000 efl=00000246
ntdll!DbgBreakPoint:
7c901230 cc int 3
0:005> !runaway
User Mode Time
Thread Time
6:10d8 0 days 0:01:04.859
0:af4 0 days 0:00:00.140
4:1190 0 days 0:00:00.078
5:ca8 0 days 0:00:00.000
3:14b8 0 days 0:00:00.000
2:858 0 days 0:00:00.000
1:a5c 0 days 0:00:00.000

Well, no hard choice here. The other threads list the same CPU time and thread 6 is obviously the culprit. I examine the thread’s stack trace:

0:005> ~6 s
eax=00000103 ebx=00000aef ecx=00000103 edx=000043c3 esi=000043c0 edi=000000ef
eip=74da9a58 esp=00bdc2ac ebp=00bdc370 iopl=0 nv up ei ng nz ac po cy
cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00000293
USP10!ScriptTokenize+0x97:
74da9a58 663b4508 cmp ax,word ptr [ebp+8] ss:0023:00bdc378=0103
0:006> k
ChildEBP RetAddr
00bdc370 74da2d44 USP10!ScriptTokenize+0x97
00bdc398 74e85840 USP10!ScriptItemize+0x42
00bdc3d0 74e84a13 riched20!CUniscribe::ItemizeString+0x8a
00bdc644 74e5f269 riched20!CTxtBreaker::OnPostReplaceRange+0x200
00bdc664 74e6b436 riched20!CNotifyMgr::NotifyPostReplaceRange+0x25
00bdc6ec 74e65825 riched20!CRchTxtPtr::ReplaceRange+0x42c
00bdc750 74e65643 riched20!CTxtRange::ReplaceRange+0x127
00bdc7b8 74e66b3e riched20!CTxtRange::CheckLimitReplaceRange+0x179
00bdca04 74e5b32b riched20!CTxtRange::CleanseAndReplaceRange+0x833
00bdfa78 74e5b8b2 riched20!CLightDTEngine::ReadPlainText+0x2c7
00bdfd30 74e7ce5d riched20!CLightDTEngine::LoadFromEs+0x287
00bdfeb8 74e7e87b riched20!CTxtEdit::TxSendMessage+0x11c9
00bdff1c 00852b90 riched20!CTxtEdit::Open+0x244
WARNING: Stack unwind information not available. Following frames may be wrong.
00bdff44 00853e4e rtffilt!DllCanUnloadNow+0xaff
00bdff74 00853eb8 rtffilt!DllRegisterServer+0x1af
00bdffac 00853f11 rtffilt!DllRegisterServer+0x219
00bdffb4 7c80b683 rtffilt!DllRegisterServer+0x272
00bdffec 00000000 kernel32!BaseThreadStart+0x37

I was quite surprised and disappointed by this stack trace. As is apparent, no symbolic information is available for rtffilt.dll. Since my Windbg is configured to use the Microsoft web symbol store, the PDB should have been downloaded automatically. I pondered, perhaps a third party product has installed this filter into the indexing service? I examined who is to blame for this sorry state of affairs:

0:006> lmv m rtffilt
start end module name
00850000 0085a000 rtffilt (export symbols) C:\WINDOWS\system32\rtffilt.dll
Loaded symbol image file: C:\WINDOWS\system32\rtffilt.dll
Image path: C:\WINDOWS\system32\rtffilt.dll
Image name: rtffilt.dll
Timestamp: Tue Feb 06 01:36:06 2007 (45C7BF66)
CheckSum: 00014877
ImageSize: 0000A000
File version: 2006.0.6000.16431
Product version: 2006.0.6000.16431
File flags: 8 (Mask 3F) Private
File OS: 40004 NT Win32
File type: 2.0 Dll
File date: 00000000.00000000
Translations: 0409.04b0
CompanyName: Microsoft Corporation
ProductName: Microsoft® Windows® Operating System
InternalName: rtffilt.lib
OriginalFilename: rtffilt.lib
ProductVersion: 2006.0.6000.16431
FileVersion: 2006.0.6000.16431 (vista_gdr(wmbla).070205-1422)
FileDescription: RTF Filter
LegalCopyright: © Microsoft Corporation. All rights reserved.

Oy vey. The RTF filter is actually a Microsoft DLL. Since this is an XP machine and the DLL version is “Vista-ish”, I quickly concluded that the DLL belongs to Windows Desktop Search 3.01, which aligns the desktop search engine on XP with Vista’s built-in search engine. The only other thing with “Vista-ish” versions on my system is Windows Script Host 5.7, which similarly, aligns WSH functionality with the Vista version. I figured the RTF filter is unrelated to that product.

It appears that whenever Microsoft releases an add-on for Windows like Windows Desktop Search, releasing debugging symbols to the symbol store is not a foregone conclusion, even if the original version of the component has its symbols already published by virtue of being a part of the Windows Vista operating system. It is obvious that the absence of the symbols is not a misguided attempt at protecting intellectual property, since they are available anyway for their Vista counterparts. For some reason, not all groups inside Microsoft have uploading public symbols to the symbol store as an integral part of their release process. When mishaps like this happen, their customers are left out in the cold to diagnose the issue on their own. Sure, in this case it was on my home computer, but it could have easily been an enterprise production debugging scenario. Missing symbols are unacceptable, Microsoft. Someone should get their ass fired.

Although taken aback, I did not give up. Since I did have symbols for the upper part of the stack trace, I could still have some impression of what was going on. I figured I’d let the filter run for a while and examine the stack again:

0:006> g
(afc.fbc): Break instruction exception - code 80000003 (first chance)
eax=7ffdd000 ebx=00000001 ecx=00000002 edx=00000003 esi=00000004 edi=00000005
eip=7c901230 esp=0078ffcc ebp=0078fff4 iopl=0 nv up ei pl zr na pe nc
cs=001b ss=0023 ds=0023 es=0023 fs=0038 gs=0000 efl=00000246
ntdll!DbgBreakPoint:
7c901230 cc int 3
0:005> ~6 k
ChildEBP RetAddr
00bdc3e8 74e848d6 riched20!CBreakArray::GetBreak+0x2a
00bdc644 74e5f269 riched20!CTxtBreaker::OnPostReplaceRange+0xc3
00bdc664 74e6b436 riched20!CNotifyMgr::NotifyPostReplaceRange+0x25
00bdc6ec 74e65825 riched20!CRchTxtPtr::ReplaceRange+0x42c
00bdc750 74e65643 riched20!CTxtRange::ReplaceRange+0x127
00bdc7b8 74e66b3e riched20!CTxtRange::CheckLimitReplaceRange+0x179
00bdca04 74e5b32b riched20!CTxtRange::CleanseAndReplaceRange+0x833
00bdfa78 74e5b8b2 riched20!CLightDTEngine::ReadPlainText+0x2c7
00bdfd30 74e7ce5d riched20!CLightDTEngine::LoadFromEs+0x287
00bdfeb8 74e7e87b riched20!CTxtEdit::TxSendMessage+0x11c9
00bdff1c 00852b90 riched20!CTxtEdit::Open+0x244
WARNING: Stack unwind information not available. Following frames may be wrong.
00bdff44 00853e4e rtffilt!DllCanUnloadNow+0xaff
00bdff74 00853eb8 rtffilt!DllRegisterServer+0x1af
00bdffac 00853f11 rtffilt!DllRegisterServer+0x219
00bdffb4 7c80b683 rtffilt!DllRegisterServer+0x272
00bdffec 00000000 kernel32!BaseThreadStart+0x37

So it looks like we went from stack bottom doing some Uniscribe work up to actual work on the RTF by the implementation in the Rich Edit library. We do not appear to be stuck in an infinite loop in Uniscribe, at least. Letting the daemon run a few more times shows that some movement between Rich Edit 2.0 functions is occurring, but it is unclear what’s making it work so hard.

A corrupt RTF file is an obvious suspect as the cause of the problem. Let’s see what the filter is working on. I was hoping to use the “!handle” extension to find out about the file handle used by the cidaemon process, but disappointingly, I could not get the extension to show the file name for a given file handle. I opted for Sysinternals’ Handle tool, which I remembered had this functionality. I reviewed cidaemon.exe’s open handles:

C:\Program Files\SysInternals>handle -p cidaemon.exe
Handle v3.2
Copyright (C) 1997-2006 Mark Russinovich
Sysinternals - http://www.sysinternals.com
------------------------------------------------------------------------------
cidaemon.exe pid: 5016 NT AUTHORITY\SYSTEM
C: File (RW-) C:\WINDOWS\system32
40: File (RW-) C:\WINDOWS\WinSxS\x86_Microsoft.Windows.Common-Controls_659
5b64144ccf1df_6.0.2600.2982_x-ww_ac3f9c03
68: Section \BaseNamedObjects\c::inetpub:catalog.wci__cisharedmem
F8: Section \BaseNamedObjects\__CiPerfMonMemory
------------------------------------------------------------------------------
cidaemon.exe pid: 2812 NT AUTHORITY\SYSTEM
C: File (RW-) C:\WINDOWS\system32
40: File (RW-) C:\WINDOWS\WinSxS\x86_Microsoft.Windows.Common-Controls_659
5b64144ccf1df_6.0.2600.2982_x-ww_ac3f9c03
68: Section \BaseNamedObjects\c::system volume information:catalog.wci_
_cisharedmem
F8: Section \BaseNamedObjects\__CiPerfMonMemory
14C: File (---) C:\Program Files\Nero\Nero 7\Core\CDI\CDI_IMAG.RTF
1D4: Section \BaseNamedObjects\ShimSharedMemory
20C: File (RW-) C:\WINDOWS\WinSxS\x86_Microsoft.Windows.GdiPlus_6595b64144c
cf1df_1.0.2600.2180_x-ww_522f9f82
264: File (RW-) C:\WINDOWS\WinSxS\x86_Microsoft.Windows.Common-Controls_659
5b64144ccf1df_6.0.2600.2982_x-ww_ac3f9c03
2A0: File (RW-) C:\Program Files\Nero\Nero 7\Core\CDI\CDI_IMAG.RTF

The offending cidaemon.exe has two open handles to an RTF file and in fact they are both for the same file. This file, CDI_IMAG.RTF, is a part of the Nero Burning ROM CD/DVD software installed on my system. This must be the file causing the RTF filter’s grief.

Attempting to confirm this is the case (although hardly anything would be able to persuade me otherwise at this point), I examine the thread’s stack yet again, this time also examining arguments:

0:006> kb
ChildEBP RetAddr Args to Child
00bdc3a8 74e795bb 00012414 00000100 00000000 riched20!CTxtPtr::FindOrSkipWhiteSpaces+0xb5
00bdc3dc 74e84889 00000001 00000101 00000100 riched20!CTxtPtr::FindWhiteSpaceBound+0xcc
00bdc644 74e5f269 00012414 00000000 00000001 riched20!CTxtBreaker::OnPostReplaceRange+0x76
00bdc664 74e6b436 00bdfe50 00012414 00000000 riched20!CNotifyMgr::NotifyPostReplaceRange+0x25
00bdc6ec 74e65825 00000001 00000001 00bdd2e8 riched20!CRchTxtPtr::ReplaceRange+0x42c
00bdc750 74e65643 00000001 00bdd2e8 00000000 riched20!CTxtRange::ReplaceRange+0x127
00bdc7b8 74e66b3e 00000001 00bdd2e8 000000ee riched20!CTxtRange::CheckLimitReplaceRange+0x179
00bdca04 74e5b32b 000003c6 00bdca78 00000000 riched20!CTxtRange::CleanseAndReplaceRange+0x833
00bdfa78 74e5b8b2 00bdfe4c 00bdfee4 00000000 riched20!CLightDTEngine::ReadPlainText+0x2c7
00bdfd30 74e7ce5d 00bdfe4c 00001011 00bdfee4 riched20!CLightDTEngine::LoadFromEs+0x287
00bdfeb8 74e7e87b 00000449 00001011 00bdfee4 riched20!CTxtEdit::TxSendMessage+0x11c9
00bdff1c 00852b90 000ba5b0 00bdff34 00000130 riched20!CTxtEdit::Open+0x244
WARNING: Stack unwind information not available. Following frames may be wrong.
00bdff44 00853e4e 00bdff64 b7ee486a 7ffdd000 rtffilt!DllCanUnloadNow+0xaff
00bdff74 00853eb8 b7ee48b2 7ffdd000 7ffdf000 rtffilt!DllRegisterServer+0x1af
00bdffac 00853f11 00bdffec 7c80b683 0007e384 rtffilt!DllRegisterServer+0x219
00bdffb4 7c80b683 0007e384 7ffdd000 7ffdf000 rtffilt!DllRegisterServer+0x272
00bdffec 00000000 00853f04 0007e384 00000000 kernel32!BaseThreadStart+0x37

Neither file handle 0x14c nor file handle 0x2a0 is immediately visible in this stack trace. Presumably the Rich Edit 2.0 library is dealing with the RTF stream in memory. Once again I am bitten by the absence of the RTF filter’s symbol and FPO information. If the stack trace had not been black-holed in the middle, perhaps associating the ongoing processing with an handle would have been easier. I realize in this case only one RTF file is open in the offending process, but I was still interested in how one could associate this operation with a specific file if the filter had been written to process many RTF files in bulk, simultaneously.

While we can’t readily see the handle’s association with the current Rich Edit processing, we can at least find old, nested function calls on the stack that used it. We can search the stack for the 0x2a0 handle, for example (little endian byte order):

0:006> s @esp L1000 a0 02
00bdc994 a0 02 00 00 00 00 00 00-00 00 00 00 00 00 00 00 ................

Let’s have a look at the stack in the vicinity of the 0x2a0 value we found to determine whether this is a false positive or actual use of the handle:
0:006> dps 0x00bdc994-20
00bdc974 74e64eab riched20!CTxtRange::Update_iFormat+0x15c
00bdc978 00000001
00bdc97c 00000000
00bdc980 00000000
00bdc984 00bdfe4c
00bdc988 00000000
00bdc98c 7c90e288 ntdll!NtReadFile+0xc
00bdc990 7c801875 kernel32!ReadFile+0x16c
00bdc994 000002a0
00bdc998 00000000
00bdc99c 00000000
00bdc9a0 00000000
00bdc9a4 00bdc9cc
00bdc9a8 00bdca78
00bdc9ac 00000ffe
00bdc9b0 00000000
00bdc9b4 7c801898 kernel32!ReadFile+0x1ca
00bdc9b8 00bdfe4c
00bdc9bc 00bdfee4
00bdc9c0 00000000
00bdc9c4 00000001
00bdc9c8 00bdfee4
00bdc9cc 00000000
00bdc9d0 00000ffe
00bdc9d4 00000000
00bdc9d8 00000000
00bdc9dc 00bdc9b8
00bdc9e0 00000000
00bdc9e4 00bdff68
00bdc9e8 7c839aa8 kernel32!_except_handler3
00bdc9ec 7c809ba8 kernel32!`string'+0xc
00bdc9f0 ffffffff

We can see the remains of a call to the ReadFile API with a file handle to the suspected RTF file on the offending thread’s stack. Had this process had more threads processing RTF files, we’d be able to make the connection between the CPU hogging thread and the problematic RTF file this way. If the process was using a thread pool and each thread was being recycled to process an RTF file after another, results could have still been inconclusive, however.

For those without Nero 7 on their systems who are wondering what’s the deal with that RTF file, it is, in fact, not a rich text format file at all. Ahead made the mistake of calling a non-RTF file with the RTF file extension, persuading the Indexing Service’s RTF filter to attempt to index it. Given all the talk from Microsoft these days on their Security Development Lifecycle, Threat Modeling and all the fuzzing they claim to be doing, it is curious that relatively modern code like the search engine’s RTF filter would happily go into a CPU hogging frenzy on an RTF file that doesn’t even bother with an RTF opening tag. Some basic sanity validation is amiss here.

I looked it up out of curiosity and apparently CDI_IMAG.RTF has something to do with the now very defunct CD-i technology, which White Book classic VCDs are required to be compatible with. I was surprised there’s actually something older than those Video CDs…

For the time being, I renamed the file so its extension won’t be RTF, to prevent the RTF filter from embarrassing itself and killing my box while doing so. Hopefully Nero won’t mind as long as I stick to 21st century technology.

Another happy ending.

Advertisements

7 thoughts on “The case of the Windows Desktop Search CPU hog

  1. You ARE…THE…MAN!!!

    Very impressive. Exact same file from a Nero 5.x install was causing the same issue on my box. Grrrrrr!

  2. Same problem seems to exist with Nero 9, which was causing my PC to bluescreen over CPU thermal shutdown…caused, of course, by cidaemon thrashing over the not really an rtf file installed by Nero. Is Nero AG just totally irresponsible since this has obviously been a problem since Nero 7? Removed Nero 9 and all is well. They can stop sending me emails for new improved upgrades til they get this kind of crap fixed.

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s