Hello, my name is Venkatesh Ganga, and I’m an Escalation Engineer on the Microsoft Platform Global Escalation Services team.  Recently, I worked on an issue where registry reflection was not happening while installing 32bit Office under the system account. This required looking into both the 32bit Office code and the Wow64 code where the registry reflection is implemented.  When attaching to the Wow64 process using the 32bit debugger it’s like debugging a 32bit process on the 32bit machine; there are no 64bit binaries in the process. However, we needed to debug Wow64 to debug the registry reflection code. To do this we attached to the Wow64 process using the 64bit debugger which allows you to see the Wow64 binaries.

Ø  lm

            Base TimeStamp                     Module

          400000 42435b2a Mar 24 18:28:26 2005 C:\Program Files (x86)\Internet Explorer\IEXPLORE.EXE

        77ec0000 45d6cc72 Feb 17 03:35:46 2007 C:\WINDOWS\system32\ntdll.dll

        6b000000 45d6943d Feb 16 23:35:57 2007 C:\WINDOWS\system32\wow64.dll

        6b280000 45d695f3 Feb 16 23:43:15 2007 C:\WINDOWS\system32\wow64win.dll

        78b80000 42438b7a Mar 24 21:54:34 2005 C:\WINDOWS\system32\wow64cpu.dll

There are 2 options for debugging Wow64 applications.

1.       Using the 64bit debugger and Wow64 debugger extension (Wow64exts.dll)

2.       Using the 32bit debugger

Using 64bit debugger and Wow64 debugger extension (Wow64exts.dll)

I ran the 32bit version of Internet Explorer on a 64bit machine and attached to it using the 64bit debugger. Here is the thread 0 call stack when viewed from 64bit debugger.

0:000> kL

Child-SP          RetAddr           Call Site

00000000`0013edf8 00000000`78b8428e wow64cpu!CpupSyscallStub+0x9

00000000`0013ee00 00000000`6b006a5a wow64cpu!Thunk0Arg+0x5

00000000`0013ee70 00000000`6b005e0d wow64!RunCpuSimulation+0xa

00000000`0013eea0 00000000`77ed8030 wow64!Wow64LdrpInitialize+0x2ed

00000000`0013f6d0 00000000`77ed582f ntdll!LdrpInitializeProcess+0x1538

00000000`0013f9d0 00000000`77ef30a5 ntdll!_LdrpInitialize+0x18f

00000000`0013fab0 00000000`77d59620 ntdll!KiUserApcDispatch+0x15

00000000`0013ffa8 00000000`00000000 0x77d59620

00000000`0013ffb0 00000000`00000000 0x0

00000000`0013ffb8 00000000`00000000 0x0

00000000`0013ffc0 00000000`00000000 0x0

00000000`0013ffc8 00000000`00000000 0x0

00000000`0013ffd0 00000000`00000000 0x0

00000000`0013ffd8 00000000`00000000 0x0

00000000`0013ffe0 00000000`00000000 0x0

00000000`0013ffe8 00000000`00000000 0x0

00000000`0013fff0 00000000`00000000 0x0

00000000`0013fff8 00000000`00000000 0x0

00000000`00140000 00000020`78746341 0x0

00000000`00140008 00005370`00000001 0x20`78746341

The above stack only shows the 64 bit calls; we cannot see what the 32 bit calls are doing. To get the 32bit stack you must use one of the below methods.

Ø  Option 1 : Run “!wow64exts.k”

0:000> !wow64exts.k

Walking 64bit Stack…

Child-SP          RetAddr           Call Site

00000000`0013edf8 00000000`78b8428e wow64cpu!CpupSyscallStub+0x9

00000000`0013ee00 00000000`6b006a5a wow64cpu!Thunk0Arg+0x5

00000000`0013ee70 00000000`6b005e0d wow64!RunCpuSimulation+0xa

00000000`0013eea0 00000000`77ed8030 wow64!Wow64LdrpInitialize+0x2ed

00000000`0013f6d0 00000000`77ed582f ntdll!LdrpInitializeProcess+0x1538

00000000`0013f9d0 00000000`77ef30a5 ntdll!_LdrpInitialize+0x18f

00000000`0013fab0 00000000`77d59620 ntdll!KiUserApcDispatch+0x15

00000000`0013ffa8 00000000`00000000 0x77d59620

00000000`0013ffb0 00000000`00000000 0x0

00000000`0013ffb8 00000000`00000000 0x0

00000000`0013ffc0 00000000`00000000 0x0

00000000`0013ffc8 00000000`00000000 0x0

00000000`0013ffd0 00000000`00000000 0x0

00000000`0013ffd8 00000000`00000000 0x0

00000000`0013ffe0 00000000`00000000 0x0

00000000`0013ffe8 00000000`00000000 0x0

00000000`0013fff0 00000000`00000000 0x0

00000000`0013fff8 00000000`00000000 0x0

00000000`00140000 00000020`78746341 0x0

00000000`00140008 00005370`00000001 0x20`78746341

Walking 32bit Stack...

ChildEBP          RetAddr          

002ded98 75ec1c83 USER32!NtUserWaitMessage+0x15

002dee24 75ec61ef BROWSEUI!BrowserProtectedThreadProc+0x44

002dfea8 779ba3a6 BROWSEUI!SHOpenFolderWindow+0x22c

002dfec8 0040243d SHDOCVW!IEWinMain+0x129

002dff1c 00402748 IEXPLORE!WinMain+0x316

002dffc0 7d4e7d2a IEXPLORE!WinMainCRTStartup+0x186

002dfff0 00000000 KERNEL32!BaseProcessStart+0x28

Ø  Option 2 : Switch to x86 mode (using “!wow64exts.sw”) and do KB.

The easiest way to see all of the 32bit call stacks is by switching to  32bit mode (!wow64exts.sw) and doing ~*k.  In addition, you can set breakpoints in 32bit or 64 bit binaries using the 64bit debugger.  Also note  “!peb” will show both the 64bit and 32bit PEB.

Using the 32bit debugger

As mentioned earlier there is nothing wrong with using the 32 bit debugger.  If you just need to debug the application’s 32bit code, using it is probably the simplest approach.  However, if you need to view Wow64 code or binaries, you must use the 64bit debugger.  Note that these techniques apply to debugging Wow64 dumps and live processes.

You can find more information about WoW64 applications at http://msdn.microsoft.com/en-us/library/aa384249(VS.85).aspx 

Hi, my name is Chad. I work as an escalation engineer for Microsoft’s OEM support team.

A while back, I encountered an interesting crash on one of my computers at home, and I thought I’d post about how I debugged it.

This particular machine had been humming along quite happily for some time, but one day while I was scanning some photos, it bluescreened. Naturally, I hoped it was just a fluke, but after it happened a few more times while doing the same thing, I decided to debug it.

Ordinarily, if a machine crashes when performing a specific activity, like scanning photos, my first inclination would be to suspect a bug in one of the drivers involved in that activity, like the scanner driver or the USB driver. But in this case, I had been using this scanner for a long time, with the same drivers, and never had this problem, so this sudden crashing was kind of mysterious.

Let's see what we can tell from the dump!

The first order of business when looking at a crash dump is the !analyze -v command. I've trimmed some of it here for brevity, but it goes something like this:

kd> !analyze -v

*******************************************************************************

*                                                                             *

*                        Bugcheck Analysis                                    *

*                                                                             *

*******************************************************************************

KERNEL_MODE_EXCEPTION_NOT_HANDLED (8e)

This is a very common bugcheck.  Usually the exception address pinpoints

the driver/function that caused the problem.  Always note this address

as well as the link date of the driver/image that contains this address.

Some common problems are exception code 0x80000003.  This means a hard

coded breakpoint or assertion was hit, but this system was booted

/NODEBUG.  This is not supposed to happen as developers should never have

hardcoded breakpoints in retail code, but ...

If this happens, make sure a debugger gets connected, and the

system is booted /DEBUG.  This will let us see why this breakpoint is

happening.

Arguments:

Arg1: c0000005, The exception code that was not handled

Arg2: 8738e300, The address that the exception occurred at

Arg3: b9b3dc7c, Trap Frame

Arg4: 00000000

Debugging Details:

------------------

EXCEPTION_CODE: (NTSTATUS) 0xc0000005 - The instruction at "0x%08lx" referenced memory at "0x%08lx". The memory could not be "%s".

FAULTING_IP:

+ffffffff8738e300

8738e300 0000             add     [eax],al

TRAP_FRAME:  b9b3dc7c -- (.trap ffffffffb9b3dc7c)

ErrCode = 00000002

eax=00000001 ebx=bc514c68 ecx=0001065e edx=bc510000 esi=00000955 edi=b9b3dd64

eip=8738e300 esp=b9b3dcf0 ebp=b9b3dd08 iopl=0         nv up ei pl zr na po nc

cs=0008  ss=0010  ds=0023  es=0023  fs=0030  gs=0000             efl=00010246

8738e300 0000             add     [eax],al                ds:0023:00000001=??

Resetting default scope

DEFAULT_BUCKET_ID:  DRIVER_FAULT

BUGCHECK_STR:  0x8E

LAST_CONTROL_TRANSFER:  from 8051d6a7 to 8053331e

STACK_TEXT: 

WARNING: Frame IP not in any known module. Following frames may be wrong.

b9b3dcec bf801619 b9b3dd64 0012eee4 bf81551f 0x8738e300

b9b3dd08 bf81553c b9b3dd64 0012eee4 bf81551f win32k!ValidateHwnd+0x5c

b9b3dd50 804de7ec 0001065e 012eb244 00000000 win32k!NtUserInvalidateRect+0x1d

b9b3dd50 7c90eb94 0001065e 012eb244 00000000 nt!KiFastCallEntry+0xf8

0012eecc 77d4b601 0105a943 0001065e 012eb244 ntdll!KiFastSystemCallRet

0012eed0 0105a943 0001065e 012eb244 00000000 USER32!NtUserInvalidateRect+0xc

77d4b601 90909090 001134b8 0300ba00 12ff7ffe NikonScan4!GetSource+0x21e93

...

From the stack trace, we can tell that NikonScan4.dll made a call into User32, which ultimately ended up calling into win32k.sys down in kernel mode. Win32k was in a function called ValidateHwnd() and then tried to call some function at address 0x8738e300, at which point we tried to dereference an invalid pointer and crashed.

What’s at 0x8738e300?

kd> dc 8738e300

8738e300  00000000 00000001 00000000 87360350  ............P.6.

8738e310  00000000 00000001 f71af9fe f71b0030  ............0...

8738e320  f71afb0e f71afbb4 f71b0098 f71b0214  ................

8738e330  f71afef6 f71aff8e 07fef800 00000000  ................

8738e340  f71afffc 00000000 0a0e000a 644c6d4d  ............MmLd

8738e350  8732ea58 870303e0 ffffffff ffffffff  X.2.............

8738e360  00000012 00000000 f797f000 f7989905  ................

8738e370  0000c000 00500050 e1971458 00160016  ....P.P.X.......

kd> !pool 8738e300 2

Pool page 8738e300 region is Nonpaged pool

*8738e2f8 size:   50 previous size:    8  (Allocated) *NV 

              Owning component : Unknown (update pooltag.txt)

Well, that’s bad. 0x8738e300 isn’t actually a valid address of a function. That location contains some user data (specifically, some nonpaged pool).

So, that's why we blew up: the ValidateHwnd() function in win32k made a call to this bad address which contains data instead of code! Let's see if we can figure out why it did this. We can find the return address in win32k!ValidateHwnd on the stack, and unassemble the instructions leading up to the point where we ran off into the weeds.

kd> kv L8

ChildEBP RetAddr  Args to Child             

WARNING: Frame IP not in any known module. Following frames may be wrong.

b9b3dcec bf801619 b9b3dd64 0012eee4 bf81551f 0x8738e300

b9b3dd08 bf81553c b9b3dd64 0012eee4 bf81551f win32k!ValidateHwnd+0x5c (FPO: [Non-Fpo])

b9b3dd50 804de7ec 0001065e 012eb244 00000000 win32k!NtUserInvalidateRect+0x1d (FPO: [Non-Fpo])

b9b3dd50 7c90eb94 0001065e 012eb244 00000000 nt!KiFastCallEntry+0xf8 (FPO: [0,0] TrapFrame @ b9b3dd64)

0012eecc 77d4b601 0105a943 0001065e 012eb244 ntdll!KiFastSystemCallRet (FPO: [0,0,0])

0012eed0 0105a943 0001065e 012eb244 00000000 USER32!NtUserInvalidateRect+0xc

77d4b601 90909090 001134b8 0300ba00 12ff7ffe NikonScan4!GetSource+0x21e93

77d4b605 001134b8 0300ba00 12ff7ffe 900008c2 0x90909090

The return address from where we made the bad call is bf801619. Let’s unassemble a few instructions backwards from that address (using the handy but often-overlooked “ub” command) and see what the code was doing:

kd> ub bf801619

win32k!ValidateHwnd+0x2f:

bf8015ff 8d1c82           lea     ebx,[edx+eax*4]

bf801602 8bc1             mov     eax,ecx

bf801604 c1e810           shr     eax,0x10

bf801607 663b430a         cmp     ax,[ebx+0xa]

bf80160b 75ad             jnz     win32k!ValidateHwnd+0x3d (bf8015ba)

bf80160d 807b0801         cmp     byte ptr [ebx+0x8],0x1

bf801611 7573             jnz     win32k!ValidateHwnd+0xff (bf801686)

bf801613 ff15e0b298bf call dword ptr [win32k!_imp__PsGetCurrentThread (bf98b2e0)]

OK, so it's pretty simple. Win32k decided which function address to call by reading it from a pointer stored at a hardcoded location (in other words, in a global variable) within Win32k itself. That pointer is located at bf98b2e0. The debugger helpfully tells us that this pointer is intended to contain the address of a function called PsGetCurrentThread, but let’s double-check this and make sure it actually does. At this point, the working assumption would be that this pointer had gotten corrupted somehow.

kd> dd bf98b2e0 L1

bf98b2e0  804e4a15

Interesting. bf98b2e0 contains the value 804e4a15. This is not even close to the bad address the processor actually called! Remember, from the stack trace, we jumped to 8738e300 instead. What does this pointer actually point to?

Sure enough, 804e4a15 is the address of nt!PsGetCurrentThread.

So, basically, win32k was trying to call PsGetCurrentThread(), and even had the correct pointer in memory to get there, but the processor instead jumped to a bogus address located in the middle of some user data.

At this point it's pretty safe to say that this is a hardware problem, and furthermore, since the relevant memory looks fine, it looks like a problem within the CPU itself. (I’m not an expert on CPU architecture, but if I were to take a wild guess I’d say that maybe the processor had some problem when reading from its L2 cache.)

Upon discovering this, I decided to crack open my case and take a look. It didn’t take long to spot the problem:

Yes, that's my CPU fan. Notice that the heatsink is completely clogged up with dust!

The resolution to this story: I took a can of compressed air and blew all the dust out of the heatsink. This took care of the problem, and the computer happily scanned hundreds of photos and hasn’t crashed again since. Why was it only crashing when I was scanning photos? Most likely because this was causing the CPU to run at 100% utilization for extended periods of time, and it was simply overheating!

Hi my name is Jason. I’m an escalation engineer on the Microsoft critical problem resolutions platform team. We recently dealt with an interesting issue that I would like to share with you and show how we went about discovering the cause. 

The customer stated that when his server (Windows Server 2003 SP1) boots up the DNS Server service does not become availabe/responsive for ~5 minutes. Customer also stated he has other DC's in this domain that are the same model server (same specs too) that do not have the problem. So I ask, "What do you mean not responsive?". During this 5 minute period, the administrator cannot use the DNS MMC to administer the server, and DNS lookups to this server fail with a timeout error. The customer can: Ping the server, connect to file shares, etc.

Troubleshooting

So my initial question was "What is DNS doing for 5 minutes?". In order to determine where dns.exe was hung up or spinning his wheels, I replaced dns.exe with the checked build.

Walkthrough:

1.     Downloaded the checked build of SP1

2.     Extracted and expanded the checked build of dns.exe (What is a checked build?)

3.     Worked through the process of replacing the free build of DNS.exe (Booting into safe mode in order to bypass WFP (Windows file protection))

4.     Created the dnsdebug file (a text file with no extension under %windir%\system32\dns). The checked build of DNS looks for this file, and reads the contents to determine the level of output. 

5.     In the file I set the debug flags for DNS_DEBUG_INIT (0x00000010 ) & DNS_DEBUG_INIT2 (0x01000000) and set the output to go to the debugger (0x00000002), net result (0x01000012). The image below shows contents of the file.
 

6.     Instead of using the debugger I decided to use DebugView from Sysinternals to view the output. I could have attached a debugger to DNS.exe to see the output, but in this case the DebugView was sufficient.

With all this in place we rebooted. We launched DebugView and did a "net start dns". Here is a screen scrape of what the output looked like:

I have highlighted the debug flag I have set.

From this output we were able to determine that the Server was going through the following process:

1.     DNS gets started by Service Control Manger (a.k.a. SCM) and then DNS communicates back to SCM (across the NtControlPipe)

2.     DNS loads the zones from the registry (HKLM\Software\Microsoft\Windows NT\Current Version\DNS Server\Zones

3.     DNS pulls this zones from the Active Directory (as this is an AD integrated zone)

During these phases the ability to respond to administrative requests and name lookup requests is blocked (this is by design). So based on this I needed to figure out where we were spending the most of our 5 minutes.

1.     For the SCM portion, I used Filemon monitoring only Named Pipes for dns.exe and services.exe.

2.     For the registry portion, I used Regmon with a filter for dns.exe

3.     For the AD portion, I used perfmon with the NTDS>LDAP Searches/Sec counter

With these running we were able to isolate the delay to the point where DNS was pulling the zones from AD. Here is a scrape of me running this test on my VM:

You can see (top left) the service communicating back to SCM across the NtControlPipe. Lets take a moment here and have a short discussion how a service starting works.

1. SCM goes to a registry value that will be used as a seed value to build a named pipe. (HKLM\System\CurrentControlSet\Control\ServiceCurrent\(default) = <a number>
2. The result is incremented by 1 and then returned back to SCM
3. SCM then creates a named pipe using NtControlPipe as the prefix followed by the numerical value from the registry. So when starting the first service, the pipe name would be NtControlPipe1 (To get a peek at these pipes download PipeList from Sysinternals)
4. The SCM then starts the service process
5. The service then goes to the same registry value and uses this seed to know which named pipe he will need to talk to in order to convey progress back to SCM.
 

We can then see (top right) the service pulling in the dns zone information from the registry. Finally we see (bottom) the small spike in LDAP searches/sec (highlighted) where the service was pulling the zone information from the AD. Until the pull of the zones from the registry and AD is complete, the DNS service does not respond to MMC administration or DNS requests.

The majority of the 5 minute delta fell into the last bucket (the LDAP queries to pull the zone data). So begins our next discussion, What causes LDAP to be slow?

So LDAP lives in LSASS.EXE. There are two LDAP interfaces in AD. The entire directory is available of TCP port 389, and then the subset of AD that is published (a.k.a. Global Catalog) over TCP port 3268. The DNS services is pulling the DNS zones from the "Entire Directory" interface.

Lsass memory usage on domain controllers has two components:

• Data structures, which are like those in other processes (i.e. threads, heaps, and stacks)
• Database buffer cache, which consists of database pages and index pages for the directory ß This is where a "In-RAM" copy of AD database would be

   

In Windows Server 2003, there is no limit to how large the database buffer cache can grow (outside of the limits of the 2GB of virtual address space that can be modified via the /3GB switch). This helps explain the behavior of lsass.exe normally being the largest value in the "Mem Usage" category in task manager on a DC.

Q. What can affect the amount of Database buffer cache that LSASS is maintaining "In-RAM?
A. Memory pressure. This could be caused by configuration (pagefile settings, etc.) or another application(s) using and paging a lot of memory on the machine.

lsass.exe on the affected machine was using 300mb in the "Mem Usage" column in task manager. The machine that was not affected was closer to 450mb. This means there was 150mb more data in the Database buffer cache, and due to this, the process is able to respond a lot faster to LDAP requests since he can pull from the RAM cache more and this limits the amount of time spent pulling this data into the cache from the DIT file on the disk.

The solution is to tune the pagefile settings to match the better performing server.

By simply increasing the pagefile from ~1 gig to ~3gig the DNS Server can be available within ~30 seconds

So what are we (Microsoft) doing about this?

Excerpt from the "Book of Longhorn"

What new DNS functionality is provided by this feature in Windows Server "Longhorn"?

The DNS Server service in Windows Server "Longhorn" includes a number of new and enhanced features compared to the DNS Server service that was available in the Microsoft Windows NT® Server, Windows 2000 Server, and Windows Server® 2003 operating systems. The following sections describe these features.

Background zone loading

Very large organizations with extremely large zones that store their DNS data in AD DS sometimes discover that restarting a DNS server can take an hour or more while the DNS data is retrieved from the directory service. The result is that the DNS server is effectively unavailable to service client requests for the entire time that it takes to load AD DS-based zones.

A DNS server running Windows Server "Longhorn" now loads zone data from AD DS in the background while it restarts so that it can respond to requests for data from other zones. When the DNS server starts, it:

• Enumerates all zones to be loaded.
• Loads root hints from files or AD DS storage.
• Loads all file-backed zones, that is, zones that are stored in files rather than in AD DS.
• Begins responding to queries and remote procedure calls (RPCs).
• Spawns one or more threads to load the zones that are stored in AD DS.

Because the task of loading zones is performed by separate threads, the DNS server is able to respond to queries while zone loading is in progress. If a DNS client requests data for a host in a zone that has already been loaded, the DNS server responds with the dat (or, if appropriate, a negative response) as expected. If the request is for a node that has not yet been loaded into memory, the DNS server reads the node's data from AD DS and updates the node's record list accordingly.

Why is this functionality important?

The DNS server can use background zone loading to begin responding to queries almost immediately when it restarts, instead of waiting until its zones are fully loaded. The DNS server can respond to queries for the nodes that it has loaded or that can be retrieved from AD DS. This functionality also provides another advantage when zone data is stored in AD DS rather than in a file: AD DS can be accessed asynchronously and immediately when a query is received, while file-based zone data can be accessed only through a sequential read of the file.

I hope you find this information helpful.

Introduction:

Event Tracing for Windows (ETW) is a system and software diagnostic, troubleshooting and performance monitoring component of Windows that has been around since Windows 2000. However, it wasn't until Windows Vista that major components of the OS were updated to heavily use ETW tracing; making it much more practical and useful.

ETW is useful from a variety of scenarios, including:

 -User & Admin: Being in control of your system and knowing what is going on.
 -User & Admin: Troubleshooting performance, hardware and OS issues.
 -Enthusiast: Learning further about the OS and the low level guts of the OS.
 -Software Developer/ISV/OEM: Investigating issues with your software's interaction with Microsoft OS & technologies
 -Hardware Developer/IHV/OEM: Investigating issues with hardware interaction with the OS, including kernel, driver subsystems, up to the user stack.

ETW is a set of technologies and tools that can absolutely complement existing tools while providing a look into the guts of the OS at a very low level.

A great article from the April 2007 edition of MSDN Magazine - http://msdn.microsoft.com/en-us/magazine/cc163437.aspx, covers ETW in great depth, and is recommended reading.

Here is graphical overview of the ETW infrastructure that covers how provider(s) log to high performance in memory buffers, which can be kept in memory in a circular buffer, or written to disk in a sequential or circular fashion.

Some uses of ETW:

Today on Windows Vista, Windows 7, and sparingly on earlier OSes; ETW is used by Microsoft Development and Microsoft Support, as well as others; to help troubleshoot issues, find root-cause of bugs, analyze performance; and a large variety of other tasks.

As it stands today, ETW has two major thrusts:

1. Exposing time-based event data similar in practicality to plain old text based logged (without the normal performance overhead). Troubleshooting logs have long been used across the industry by software developers and IT professionals to troubleshoot issues. Here are some examples of how ETW logging is used.

First off, shown below is Windows Event Viewer enabling viewing of analytic and debug logs (which show you many more logs than the default view):

A variety of logs can be viewed graphically using the Event Viewer or via the built-in command line OS utility – wevtutil. There are a quite a variety of logs that are enabled by default and are available via the Event Viewer or in a kernel memory dump.

Since ETW is also a foundational component, you might find it appearing in other troubleshooting utilities. For example, Office Communications Server 2007 uses ETW for troubleshooting.

ETW is used to monitor for network events from the kernel which are then added to Process Monitor, a utility from Microsoft Sysinternals. You should also see tools such netsh and NetMon being able to capture and decode ETW traces.

There are many other methods and utilities to view the ETW tracing providers available, which may be found in the OS, via the Device Driver Kit (DDK), enabled with Microsoft products (such as Exchange or IIS), or used by tools, such as Office Communication System Logging.

The second major thrust of ETW is exposing performance data.

2. Performance data is exposed from the lowest levels of the kernel, driver subsystems, and every major user-mode component of Windows (such as Windows Media Player).

Performance data can be used in a hybrid fashion both for troubleshooting and performance reasons. Take for example a built in OS tool that uses ETW tracing to provide rich data - Resource Monitor.

Resource Monitor is available from the Windows Task Manager - Performance Tab. The cool thing about Resource Monitor is that it internally uses kernel ETW tracing to gather its data, providing rich data from the kernel itself; and thus providing a practical exposure of ETW technology for Administrators to troubleshoot their systems. This goes beyond the data that Task Manager provides, which often tends to be based on performance counters which you cannot drill down into further.

Resource Monitor is useful from both a performance standpoint, as well as troubleshooting. For example, you can view top cpu users, top disk users (why your disk is thrashing), or search for a locked file handle that is open.

For a deeper drill-down into performance data XPerf can be used to capture ETW traces and make them available for decoding offline (on another box).

Here, Xperf (available with the Windows DDK and as a standalone download) is shown looking at Internet Explorer's file access time.

There have been several posts on the NTDebugging Blog regarding XPerf, other blog posts, as well as the Windows Performance Analysis Dev Center.

Where to go from here:

In Windows 7 and Windows Server 2008 R2, ETW tracing has even been further improved with many more providers including 600+ inbox providers’ registered on the box. This number increases when add-on features or products are installed (such as Hyper-V).

The tracing provided by ETW, whether it is used directly in the OS, or via add-on tools, provides deep insight into Windows and how it works. We will explore ETW in depth in future blog posts.

Share this post :

Hello. It’s Ryan Mangipano again (Ryanman). Today’s blog will be the first in a multi-part post designed to help you understand the output of the !PTE debuger comand along with the basics of hardware Virtual Addressing.  To better understand Virtual Addressing, we will use the debugger to manually translate a 4-KByte Page Table PAE virtual address into the actual physical addresses in order to understand what !PTE is displaying. I’ll provide relevant information about Virtual Addresses and Virtual Memory along the way.  

We’ll start by translating a non-prototype valid hardware VA from an x86 PAE system

The actual process of manually decoding a virtual addresses is going to vary according to the architecture (x86, x64), size of the page, whether or not the virtual address is a large page, whether the page is marked as valid, whether it’s a hardware or software PTE, and whether PAE is enabled. For simplicity, we will not be going over the table entry (PTE/PDE)  flags until part two of the blog. For my first example, I am going to demonstrate how to use the information in the processor manuals together with the debugger to decode a valid non-prototype virtual address into the physical memory that it references.  You can then try this on your own using windbg and the !pte command to validate your findings.  

Finding an address to translate

To start, we'll need to locate a virtual address that maps to a valid PTE. I am going to use the following highlighted virtual address which I found in a memory dump.  

f9a12d0c ff155400a1f9    call    dword ptr [sfilter+0x4054 (f9a10054)]

Get out your processor manuals

The AMD and Intel manuals both contain helpful reference material on this subject. PDFs of these manuals are available online. Since my CPU is an Intel, I’m going to refer to the Intel manuals.

1: kd> !cpuinfo

CP  F/M/S Manufacturer  MHz PRCB Signature    MSR 8B Signature Features

 0 15,6,4 GenuineIntel 3192 0000000400000000                   a0073fff

My Intel manuals arrived on CD via snail mail a few days after placing my free order:

http://www.intel.com/products/processor/manuals/order.htm

Is PAE in use?

On this Intel x86 system, we first need to determine if we are using PAE. In the Intel “System Programming section 3.6.1 Paging Options” I found that the PAE (Physical Address Extension) flag can be found in bit 5 of the CR4 register. The PG (Paging) flag in CR0 which enables paging must of course also be set. Register bit numbering starts at zero so it’s the fifth bit from the right. Let’s examine cr4 and convert the value it contains into binary:

1: kd> r cr4

cr4=000006f9

1: kd> .formats 000006f9

  Binary:  00000000 00000000 00000110 11111001

You can use the debugger to check for other flags in the same manner

You can use the above method to check for other flags that you find documented in the processor manuals. For example, you can see that bit 4 is also set in the cr4 register output above. This is the Page Size Extensions (PSE) bit which enables large page sizes.

Terminology

Paging is simply a method of dividing up the linear address space into chunks. Pages are simply the name that we give to the chunks that result. The size of these sections is referred to as the Page Size. On x86 systems, the standard page size is 4-KBytes.  A Large Page means that the page is larger than the standard size (2MB on PAE x86 or 4MB on non-PAE x86).

Keep the last three

On a standard 4-KByte page size virtual address, the address f9a10054 can be thought of as being split up as follows:

 Information needed to locate the base of the page in physical memory      f9a10       

Offset into that physical page once it is found                               054

This means that the last three hexadecimal digits of our physical address will also be 0x054. Once we find the base of our physical page(which will always end in three zeros), we can simply add it to the offset 0x54 and we will have our physical address.

Are there any commands that work with physical addresses?

We will also need a way to work with these physical addresses. Most of us are familiar with using the dd command with virtual addresses. There is also a command that accepts a physical address instead of a virtual address:  !dd  (notice the ! before the command). There are also variants of the !dd command, such as !db , !du , !dq.

What data do we need to obtain to perform this conversion?

We need to determine how to use the f9a10 portion of the virtual address to find the physical page base. The Memory Management System sets up and maintains a hierarchy of tables that keep track of the mappings between virtual addresses and physical addresses. You will need the following information to traverse the tables yourself and convert this address.

1.       Starting point. This will be in the form of a pointer to the base of the first table that you need to check

2.       The number of table levels in use on the system and the size of each entry in the tables on our system

3.       The offsets into the different tables and the bases of each table.

Once you have all the above information, you can use the debugger to traverse these tables.

Let’s get our plan together for how we are going to obtain these three pieces of information

1.      Starting point. This can be obtained from the PDBR. The CR3 register is known as the Page Directory Base Register (PDBR) which points to the physical address of the base of the first table.

2.      The number of table levels in use on the system and the size of each entry in the tables on our system. This information can also be obtained from the Intel processor manuals. As previously mentioned, the number of tables, the size of the entries in the tables, the flags, where the bits are split up, and the names of the tables vary according to platform and if you are using PAE or not.  All of these, however, use the same basic concepts:

Register pointing to a àTable with entries pointing to a table à with more entries pointing to à another tableà pointing to the physical address of the page in memory.

Table1: By reading the Intel Processor Manual “System Programming:  Section 3.8, Physical Address Extension”, I was able to determine that the first table used for x86 PAE virtual addressing is called the Page-Directory-Pointer Table. It’s a table with only 4 Entries that are 64 bits (which is 8 bytes) wide. Each entry is referred to as a Page Directory Pointer Entry and abbreviated as PPE, PDP or PDPE depending on the source.  These entries provide the index into the page directory, which is known as the Page Directory Index (PDI). One of these four pointers will lead you to the physical address of the base of the next table that you need to visit in the x86 PAE hierarchy.  Just like the pointer that we used from the CR3 register, some of the bits in these table entries are not used as part of the index (referred to as a pointer in some documentation). We will grab the relevant bits and add the appropriate number of zeros to the index to obtain our physical address pointer.  I will cover what these other bits are used for in part two of this blog. We must substitute zeros for these bits.

Table2: The table at the second level of tables in the x86 PAE hierarchy (which is referenced by the pointers in Table Level One) is called the Page Directory Table.  Don’t confuse this with the Page-Directory-Pointer Table. Each Page Directory table can hold 512 entries which are 64 bits in size. The entries in this table are called Page Directory Entries (PDE) and they provide Page Table Index (PTI). Just like the last table, these entries contain indexes (which we convert to a pointer by simply adding zeros) to the base of the next table in the hierarchy.

Table3:  The last table is referred to as the Page Table. Each Entry in the page table is called a Page Table Entry (PTE) and provides the Page Offset.  Just like the last table, not all the bits are used for pointers. Each page table contains up to 512 entries which are also 64 bits in size. Each 64 bits entry in the table contains a pointer to the base of the page in physical memory.

In summary there are 3 levels of tables when using x86 PAE.  These are the Page Directory Pointer Table, Page Directory Tables, and the Page Tables.

1.      The offsets into the different tables and the bases of each table.

Each table above is a listing of indexes that will be used to locate the base of the next table. However, once we arrive at each table, we will need to know the index or offset into the table in order to know which table to get to next. These offsets into the tables can be obtained from the virtual address itself.  Let’s review our virtual address again.  However, this time we will break the address down in binary:

 Virtual Address: f9a10054

1: kd> .formats 0xf9a10054

  Binary:  11111001 10100001 00000000 01010100

Page Directory Pointer Index(PDPI)       11                        Index into 1^st table(Page Directory Pointer Table)

 Page Directory Index(PDI)                    111001 101          Index into 2^nd table(Page Directory Table)

Page Table Index(PTI)                            00001 0000          Index into 3^rd table(Page Table)

Byte Index                                               0000 01010100    0x054, the offset into the physical memory page

So as you can see, the virtual address is nothing more than a bunch of indexes/offsets. 

Putting all this data together to find the physical address

Now that we have all the required data, let’s proceed to locate our physical address

1.       Obtain our base pointer to the first table.  As we discussed earlier, we can obtain this value from the cr3 register.  Bits 0-4 of this register are not used for the pointer to the table base.  This means that in order to get the base pointer, we will need to replace these 5 least-significant bits with zero. This will result in the table base being located on a physical address that is always aligned to a 32-bit boundary. 

Keep in mind that CR3 will have a different value here for each process. You must make sure that you are in the appropriate process context before proceeding.  This is because user mode tables are specific to a particular process. Notice that I said processes, not threads.  CR3 will not be changed when swapping threads, since each thread in a given process shares the same address space.  Tables relating the system address space (kernel mode) are shared between all processes.

We’ll need to dump out the CR3 register (PDBR) in a format where we can view the last 5 bits. As you can see in the .formats output below, the 5 least significant bits are already set to zero. This means that the hexadecimal value located in the cr3 register is a pointer to the base of the first table. So we now have our starting point.  Physical address 023406e0 is the base of the first table.

1: kd> .formats @cr3

  Hex:     023406e0

  Binary:  00000010 00110100 00000110 11100000

The proper way to display the pointer out the value would be to & against the following mask

1: kd> ? 0y11111111111111111111111111100000

Evaluate expression: -32 = ffffffe0

1: kd> .formats (@cr3 & ffffffe0)

  Binary:  00000010 00110100 00000110 11100000

You can use the!process command to get and/or verify this value.

1: kd> !process

PROCESS ff981a58  SessionId: 0  Cid: 0d54    Peb: 7ffde000  ParentCid: 0550

    DirBase: 023406e0  ObjectTable: e1541510  HandleCount:  30.

You can also obtain this information from the EPROCESS structure.

1: kd>  dt nt!_EPROCESS ff981a58 Pcb.DirectoryTableBase

   +0x000 Pcb                    :

      +0x018 DirectoryTableBase     : [2] 0x23406e0

2.       Obtain our base to the second table by finding our index into the first table.  The first table (Page Directory Pointer Table) only has 4 entries and each entry is 64 bits wide. We know from the first two bits of the Virtual Address above that our offset into this table is 0y11  (The y tells the debugger the value is binary, instead of eleven). Eleven would be represented in the debugger as 0n11. We can simply multiply the offset (0y11) by the size of each entry and add the result to the base of the table to get our entry. The entries in the table are 8 bytes wide. We shall use sizeof() as shown below to obtain this value.  We can pass this math to the !dq command to dump the data at these physical addresses.

1: kd> !dq (@cr3 & 0xffffffe0)+(0y11*@@(sizeof(nt!_MMPTE))) L1

# 23406f8 00000000`05503801

The processor manuals indicate that the first 12 bits of the entry above are not part of the pointer and must be discarded.  This will cause alignment on 4KB boundaries. Since each Hex digit above represents 4 bits, this means that we need to change 801 to 000. That gives us our physical address of the base of our second table, 05503000. We will accomplish this in the next step by ANDing our PDE against a mask.

3.       Obtain our base to the third table by finding our index into the second table. The Second Table (Page Directory Table) works the same way, except that this table contains up to 512 entries (on PAE systems).  Keep in mind that there can be more than one Page Directory Tables for each process on a PAE system, however we are only concerned with the one that contains the data relating to our virtual address.  We know from the virtual address that the offset into this table is 0y111001101.  Calculate the address in the same manner as before. We will also need to set the last 12 bits to zero, just like before.

1: kd> !dq (0x05503801 & 0xFFFFFF000) +( 0y111001101*@@(sizeof(nt! _MMPTE))) L1

# 5503e68 00000000`0102d963

The last three hexadecimal digits must be changed to zero, since they are not part of the pointer. This gives us the base address of our last table, the page table, 0x0102d000

4.       Find the base of the physical page our memory resides in by finding our index into the third table. Using the base of the page table from the previous step, let’s add the index into this table that we obtained from the virtual address, 0y000010000. The last three digits need to be set to zero.

1: kd> !dq (0x102d963&0xFFFFFF000)+(0y000010000*@@(sizeof(nt! _MMPTE))) L1

# 102d080 00000000`02010121

5.       So now we have the physical address of the base of the page, 2010000 Add the base of the page to our offset from the virtual address, 0x054.

1: kd> ? (2010121 & 0xFFFFFF000) +0x054

Evaluate expression: 33620052 = 02010054

A shortcut is to simply change the 0x121 to 0x054 in the previous step.

6.       Now, let’s dump out the data at our physical address and the virtual address

1: kd> !dd (2010121 & 0xFFFFFF000) +0x054 L2

# 2010054 804ef09c 804ef12c

1: kd> dd 0xf9a10054 L2

f9a10054  804ef09c 804ef12c

                You can see that the data displayed by the two commands is the same.

7.       Now let’s dump out the virtual address using the !PTE extension. Notice the values that it provides you with. Look above and compare the values displayed above to what is displayed below. You should now understand what the highlighted and bolded fields mean.

1: kd> !pte 0xf9a10054

               VA f9a10054

PDE at 00000000C0603E68    PTE at 00000000C07CD080

contains 000000000102D963  contains 0000000002010121

pfn 102d       -G-DA--KWEV    pfn 2010       -G--A—KREV

The virtual addresses in italics represent the virtual address of the PDE (Page Directory Entry) and the PTE (Page Table Entry). Also, please note that PFN represents Page Frame Number. PFN is the term used to describe what I referred to as “pointers to the base of the next table” in the hierarchy.  This is because it really isn’t a pointer; it’s an index into the table.

Hopefully, the output of !PTE makes a lot of sense to you now. In part two of this blog, I’ll discuss what the PDE/PTE flags (-G-DA—KWEV) represent and provide an example of manual conversion of x86 PAE Large Page Virtual Addresses to Physical.

Trey Nash here again, and I would like to discuss a scenario we are all too familiar with.  You’ve worked your tail off for the past year, and for the past couple of months you even worked evenings and weekends.  Management rewarded your team with two weeks off in appreciation of your efforts.  But now that you’re back in the office, you’re hearing rumors percolating up from your tech support department that there are some cases where your application is crashing in the field for mysterious reasons.  What do you do?

The application happens to have been built with an unhandled exception filter registered via the AppDomain.UnhandledException event.  Therefore, you at least know that the application is failing with an InvalidCastException, but you cannot imagine why this is happening.

Wouldn’t it be nice if you could live debug on the affected system?  Unless you work on-site for your customer or your software is on a laptop and your customer is willing to send it to you, then I doubt you will get this opportunity.  What you need is a tool to capture the state of your application while it is failing.  Then the customer could capture this information and send it to you.

Enter ADPlus.  ADPlus is a free tool in the Debugging Tools for Windows package that scripts the CDB debugger allowing you to capture dumps for one or multiple processes on a system.  It also offers the following advantages:

·         ADPlus can monitor desktop applications, services, etc.

·         ADPlus can monitor multiple processes on the system.  When it collects a dump of those processes, it freezes and dumps them simultaneously.  This is essential for tracking down problems with inter-process communications.

·         ADPlus supports xcopy deployment meaning the customer does not need to install anything via Windows Installer, etc.  This minimizes configuration changes on the machine, and that is music to customers’ ears.  

With all of that said, let’s see how ADPlus can help you diagnose problems with .NET applications.

The Sample Application

In the rest of this post, I will reference the C# 3.0 sample application that I have put together to illustrate using ADPlus to capture an unhandled exception in a .NET application.  The code is listed below:

using System;

using System.Linq;

using System.Runtime.Serialization;

class A

{

    public void SaySomething() {

        Console.WriteLine( "Yeah, Peter...." );

        throw new BadDesignException();

    }

}

class B : A

{

}

class C

{

}

class EntryPoint

{

    static void Main() {

        DoSomething();

    }

    static void DoSomething() {

        Func<int, object> generatorFunc = (x) => {

            if( x == 7 ) {

                return new C();

            } else {

                return new B();

            }

        };

        var collection = from i in Enumerable.Range( 0, 10 )

                         select generatorFunc(i);

        // Let's iterate over each of the items in the collection

        //

        // ASSUMING THEY ARE ALL DERIVED FROM A !!!!

        foreach( var item in collection ) {

            A a = (A) item;

            try {

                a.SaySomething();

            }

            catch( BadDesignException ) {

                // Swallow these here. The programmer chose to

                // use exceptions for normal control flow which

                // is *very* poor design.

            }

        }

    }

}

public class BadDesignException : Exception

{

    public BadDesignException() { }

    public BadDesignException( string msg ) : base( msg ) { }

    public BadDesignException( string msg, Exception x ) : base( msg, x ) { }

    protected BadDesignException( SerializationInfo si,

                                  StreamingContext ctx )

        :base( si, ctx ) { }

}

You can compile this sample code easily by putting it in a file, such as test.cs, and then from either a Visual Studio Command Prompt or from a Windows SDK Command Shell, execute the following:

csc /debug+ test.cs

The notable section of the code to focus on is the foreach loop within the EntryPoint.Main() method.  In that foreach loop, we are iterating over a collection of objects where we are assuming that they all derive from type A.  Thus the code attempts to cast all instances to a reference of type A and since I have intentionally put an instance of type C within that collection, it will fail at some point with an exception of type System.InvalidCastException.

Capturing the Problem

Using ADPlus in crash mode, we can capture the exception in the customer’s environment.  To illustrate this in action, let’s launch ADPlus in crash mode and monitor the test.exe example application built above by using the following command line:

adplus -crash -o c:\temp\test -FullOnFirst -sc c:\temp\test\test.exe

ADPlus is easier to launch if you add the directory where the Debugging Tools for Windows was installed to your PATH environment variable.  The command line above assumes this has been done.  Now, let me explain the command line options that I used above.  I highly recommend that you become familiar with all of the ADPlus command line options.

·         -crash launches ADPlus in crash mode.  This is the mode you want to use if your application is failing because of an unhandled exception.

·         -o c:\temp\test tells ADPlus that I want the output to be placed in c:\temp\test, which is the directory in which I built the test.exe application.

·         -FullOnFirst is very important for managed applications..  This tells ADPlus to grab a full process dump on first chance exceptions.  It is essential that you capture full dumps for managed applications, otherwise, all of the necessary data regarding the execution engine and the managed heap will be absent from the dump making it impossible to debug effectively.

·         -sc c:\temp\test.exe is only one of the ways you can point ADPlus to an application to monitor.  In this case, we’re instructing ADPlus to tell the debugger to explicitly launch the application.  Had it been a service, or if the application you want to monitor is already running, we would probably have used –p to attach to its PID or –pn to attach to the process by name.  Notice that I provided the full path to the application.

After you launch ADPlus, you are presented with the following dialog unless you use the –quiet option.

Once the application is finished executing, go to the directory that you specified in the ADPlus –o command line option and you should see a subdirectory named similarly to what you see in the previous dialog snapshot.  For the instance of test.exe I just executed, that directory is named Crash_Mode__Date_05-11-2009__Time_21-12-54PM.  Under that directory, there are quite a few files that I have listed below:

C:\temp\test\Crash_Mode__Date_05-11-2009__Time_21-12-54PM>dir /b
ADPlus_report.txt
CDBScripts
PID-0__Spawned0__1st_chance_CPlusPlusEH__full_15ac_2009-05-11_21-13-01-332_0eac.dmp
PID-0__Spawned0__1st_chance_NET_CLR__full_15ac_2009-05-11_21-12-55-482_0eac.dmp
PID-0__Spawned0__1st_chance_NET_CLR__full_15ac_2009-05-11_21-12-56-527_0eac.dmp
PID-0__Spawned0__1st_chance_NET_CLR__full_15ac_2009-05-11_21-12-57-370_0eac.dmp
PID-0__Spawned0__1st_chance_NET_CLR__full_15ac_2009-05-11_21-12-58-103_0eac.dmp
PID-0__Spawned0__1st_chance_NET_CLR__full_15ac_2009-05-11_21-12-58-867_0eac.dmp
PID-0__Spawned0__1st_chance_NET_CLR__full_15ac_2009-05-11_21-12-59-663_0eac.dmp
PID-0__Spawned0__1st_chance_NET_CLR__full_15ac_2009-05-11_21-13-00-505_0eac.dmp
PID-0__Spawned0__1st_chance_NET_CLR__full_15ac_2009-05-11_21-13-02-689_0eac.dmp
PID-0__Spawned0__1st_chance_Process_Shut_Down__full_15ac_2009-05-11_21-13-27-743_0eac.dmp
PID-0__Spawned0__2nd_chance_NET_CLR__full_15ac_2009-05-11_21-13-04-140_0eac.dmp
PID-0__Spawned0__Date_05-11-2009__Time_21-12-54PM.log
Process_List.txt

For each first chance exception, a dump file (.dmp) has been collected.  Notice that the dump files can tend to be very large because of the –FullOnFirst option.  You can subsequently load these dump files into either Windbg (or its variants) or the Visual Studio Debugger.  Personally, I prefer Windbg because I can then load the SOS extension along with the SOSEX extension and dig into the state of the application and the CLR.

Using the ADPlus default configuration as we have above, you can see that ADPlus generated dumps for one first-chance C++ exception, eight first-chance CLR exceptions, one second-chance CLR exception and one dump collected during process shut down.

What is Included in the Output

If you look in your Debugging Tools for Windows directory, you’ll notice that ADPlus is really just a very complex VBScript.  It generates quite a bit of useful information along with any problem dump files.  ADPlus_report.txt reports the configuration for ADPlus for this run.  This is handy if you need to know what it will do for a specific type of exception.

Process_list.txt is generated from executing tlist.exe, another tool that comes with Debugging Tools for Windows.

And finally, the CDBScripts subdirectory contains a .cfg file which is the exact debugger script ADPlus generated and subsequently fed to CDB to get the job done.  On my machine, when running against the sample application using the command line from the previous section, this file is named PID‑0__Spawned0.cfg.  If you’re ever curious or need to know exactly what ADPlus instructed the debugger to do, this file is the source.

I don’t recommend executing this debugger script in a live debugger as doing so could overwrite the data that you already have collected.  Instead, if you need to couple ADPlus with live debugging, you should use the –gs option which I will describe shortly.

Pinpointing a Specific Exception

You’ll notice that in the previous run of ADPlus, quite a few dump files were generated and each one was fairly large.  In reality, there are times where a first chance exception does not always indicate a fatal situation.  In Accelerated C# 2008, I go into detail regarding how it is poor design practice to implement any sort of control flow or otherwise reasonably expected behavior using exceptions.  This is because exceptions are supposed to be truly exceptional events!  For more juicy details on how expensive exceptions are, I invite you to read an excellent blog post by Tess Ferrandez on the topic. At any rate, you may encounter situations where you get a lot of dumps for first chance exceptions you are not interested in as this example shows..

To alleviate this situation, you can create an ADPlus configuration file coupled with the !StopOnException command provided by the SOS extension to instruct ADPlus to filter out only the exceptions you’re interested in.  To do this, I created a configuration file named filter.config with the following contents:

<ADPlus>

    <!-- Configuring ADPlus to log only exceptions we're interested in -->

  <Exceptions>

     <Config>

        <!-- This is for the CLR exception -->

       <Code> clr </Code>

       <Actions1> Log </Actions1>

       <CustomActions1> .loadby sos mscorwks; !StopOnException System.InvalidCastException 1; j ($t1 = 1) '.dump /ma /u c:\dumps\InvalidCastException.dmp; gn' ; 'gn'  </CustomActions1>

       <ReturnAction1> VOID  </ReturnAction1>

       <Actions2> Log </Actions2>

     </Config>

  </Exceptions>

</ADPlus>

The <CustomActions1> element is the element of interest in this configuration file.  This element allows you to specify which commands the debugger should execute on first chance exceptions.  Within this element, you can put any valid debugger commands (except windbg GUI-related commands).  If you need to execute multiple commands, as I have above, you simply separate them with semicolons.  In the <CustomActions1> element shown above, I first load the SOS extension using the .loadby command.  Then, I use the !StopOnException command in predicate mode to set the $t1 pseudo-register to 1 if the exception is of type System.InvalidCastException and 0 otherwise.  Then, the following j command is used to create a full dump if $t1 is 1 and do nothing otherwise.  The gn command in both paths of the j command tells the debugger to go unhandled so that the exception is propagated up rather than swallowed by the debugger.  If you were to go handled, thus swallowing the exception, the exception handlers in the code would never see it and the debugger would alter the behavior of the application.  And finally, note that the .dump command used to create the dump indicates the path where the dump will be stored.  In this case, I am placing it in the c:\dumps directory on my machine.

Now you can provide this configuration file to ADPlus using the following command:

adplus -crash -o c:\temp\test -FullOnFirst -c c:\temp\test\filter.config -sc c:\temp\test\test.exe

Notice that there are fewer dumps collected.  Along with the dump for the InvalidCastException, it also captures a C++ exception as well as when the application shuts down.  If you open the C++ exception dump in the debugger and inspect the stack, it shows that the CLR is in the process of generating the InvalidCastException.  The CLR catches the C++ exception and converts it into a managed exception.  The C++ exception dump was generated because I left the –FullOnFirst option in the previous command line.  You can eliminate the C++ exception dump by removing -FullOnFirst.

Using ADPlus during Live Debugging

I already hinted at the –gs ADPlus command line option earlier in this post.  This option allows you to create the debugger scripts ADPlus creates without actually running them in the debugger.  For example, if you execute the following command (I executed mine from my c:\temp\test directory):

adplus -crash -o c:\temp\test -FullOnFirst -c c:\temp\test\filter.config -gs livedebug

You will notice that ADPlus does not actually launch any debugger or your application.  Rather, it creates a subdirectory named livedebug.  When you go into that directory, you’ll notice it looks similar in layout to the crash directories created in the previous demonstration.  On my machine, I end up with the following two files:

C:\temp\test\livedebug\ADPlus_report.txt
C:\temp\test\livedebug\CDBScripts\PID-0__livedebug.cfg

The PID-0__livedebug.cfg file is actually a debugger script file containing debugger commands.  All we have to do now is launch our test application in the debugger and then execute this script.  Within my c:\temp\test directory, I can launch the debugger using the following command:

windbg test.exe

Once inside the debugger, I can invoke the ADPlus debugger script by executing the following $$< command:

$$<C:\temp\test\livedebug\CDBScripts\PID-0__livedebug.cfg

Once you execute the $$< command, you will notice that the script takes over and performs the same actions as ADPlus does when run conventionally from the command line.

As a further experiment, edit the filter.config file and remove the gn commands.  Now the debugger will wait for user input after executing the custom commands rather than continuing execution of the application.  This could be handy if you want the opportunity to perform debugging by hand if ADPlus encounters a certain situation.

First Chance vs. Second Chance Exceptions

Throughout this post, I have been focusing on first chance exceptions for the sake of illustration.  However, many times, you are only interested in the truly unhandled exceptions.  In that case, you would want to capture only second chance exceptions.  You certainly would want to capture first chance exceptions if you needed to capture the state at the exact point the exception was thrown and before the OS searches for any handlers.  Additionally, if you suspect that the application you are debugging may be handling an exception inappropriately (maybe even blindly swallowing it), then you certainly want to catch first chance exceptions in that case.

Conclusion

In this blog post I have introduced you to ADPlus and the utility it provides when troubleshooting problems in the field.  ADPlus lends itself well to capturing exceptional situations in the field since it requires no configuration changes on the affected machine thus making it an easy pill for your customers to swallow.  You may also find this very useful when working with your Quality Assurance team during the development phase.  For example, how many times have you encountered a situation where a problem only presents itself on a dusty old rarely-used machine in the back corner of a random QA engineer’s office?  How many times, in such situations, have you felt like the only way to trouble shoot the problem effectively is to install the Visual Studio debugger and start working on that machine?  Furthermore, what if the problem only happens on that dusty old machine about once a week.  ADPlus can help you avoid that madness by providing an easy mechanism for capturing full process dumps on the troubled machine so you can then take those dumps to your trusty development machine for further debugging and analysis.

Have fun out there!

Share this post :