March, 2009

Revisiting the EnumProtocols bug (where EnumProtocols always returns –1 and GetLastError returns ERROR_INVALID_DATATYPE (0x0000070C == 1804)): I had a chance to test this out on Win 7 beta recently. I’m happy to report this issue appears to be fixed. Yay! Of course, this won’t help with the Exchange issue, but it’s nice to see someone on the Windows team noticed this bug and corrected it.

It’s true. Kills it. Kills it dead. Ok – maybe that’s a bit strong. Here’s the issue. If you installed the Microsoft Office Outlook Connector, then ran an application (other than Outlook) which uses both MAPI and Winsock, the Winsock portion of your application is likely to find its connections torn down when you’re done using MAPI. This, of course, can be quite disconcerting.

A bit about the connector: The Microsoft Office Outlook Connector is a set of MAPI provider and an Outlook Add-in that allow Outlook to connect to Microsoft Windows Live Hotmail and Microsoft Office Live Mail accounts. The file msncon32.dll implements a store, transport, and address book provider. Incidentally, the store provider is a Wrapped PST. The Add-in allows for some custom UI.

The problem is with the connector’s connection monitor feature, which uses Winsock. This feature is designed only to run when the providers were loaded inside the Outlook process, presumably when it would have access to the Add-in. However, the code which cleans up after the feature was running no matter where the providers were loaded. Since this code assumed Winsock had been initialized with WSAStartup, it cleaned it up with a call to WSACleanup. This is harmless if Winsock isn’t being used, but if it is, this tears down Winsock before the rest of the application is expecting it to be torn down. Not ideal.

The fix, of course, is only to call WSACleanup if we’ve called WSAStartup. The latest version of the Outlook Connector does just that. You can get the connector here:

http://www.microsoft.com/downloads/details.aspx?familyid=9A2279B1-DF0A-46E1-AA93-7D4870871ECF

The file with the fix in it is msncon32.dll – the fixed version is 12.0.6423.1000. Any version of msncon32.dll prior to this build will exhibit the behavior of making the unmatched call to WSACleanup. If you’re looking to code around this issue for earlier builds, you could always stack an extra call to WSAStartup to counteract the extraneous WSACleanup.

BTW – this isn’t the only fix in the connector. I don’t know if we’ve published a list of fixes. I do know one of the fixes has to do with a failure to complete migration of more than 250 calendar items from some older system to Windows Live Calendar.

We don’t get many calls here in Developer Support asking for help writing Security Labels for Outlook, but those calls we do get have always been difficult to work. The primary reason for this difficulty is the only documentation we had for creating a Security Label Policy Module was an old technical article for Outlook 2000. While there was nothing really wrong with the article, the original sample code didn’t work with Outlook 2007 and wouldn’t even compile with modern compilers.

We’ve decided to correct this. We’ve updated the article and put together an updated sample that works with Outlook 2007. Here’s the new article:

http://msdn.microsoft.com/en-us/library/dd553631.aspx

and the updated sample:

http://code.msdn.microsoft.com/dvespa/Release/ProjectReleases.aspx?ReleaseId=1893

Enjoy!

We had a customer who used CDO to create appointments and send meeting requests. Since they were operating in Europe, it wasn’t unusual for these items to have the Euro symbol (€) in the body of a meeting. When they would send the appointment, if the recipient was on Exchange 2007, all the Euro symbols would get replace with question marks.

What was happening? When you call .Send on an appointment using CDO, CDO builds a new meeting request message. It copied PR_BODY from the source appointment over to the request message. It doesn’t set a code page, so the default code page of Windows 1252 gets used, meaning the Euro is encoded as 0x80. When the message is received by Exchange 2007, it passes through the edge transport, where we process the meeting to create a tentative item on the recipient's calendar. This is where the trouble happens – we try to figure out the code page of the item. We settle on Windows 1252, which is correct, but we decide to map this to the character set ISO-8859-1, which is not quite correct. Windows 1252 and ISO-8859-1 are quite similar, but there are characters, such as the Euro, which are present in Windows 1252 but not in ISO-8859-1. We manage to read the Euro character from the source text and recognize it as the Unicode character U+20AC, but since this character isn’t present in the target code page, we write the question mark instead.

Now – if we had control over the meeting request CDO built, we could set the code page property (PR_INTERNET_CPID) to something like 1200, which fakes Exchange into keeping the Euro. However, the proper fix here is to adjust how Exchange interprets the data in the meeting request, specifically, mapping Windows 1252 to ISO-8859-15.

This is where Exchange 2007 SP1 Rollup 7 comes in. As described in this article, we’ve corrected how we map characters on inbound meeting requests, so all your Euro symbols should now be safe. If you’re receiving meeting requests with question marks in them, you should consider installing this rollup.

I wanted to take a look at HrQueryAllRows today. This is a popular function, especially among novice MAPI programmers. It seems ideal – you can pass your tag array, restriction, sort order all to one function and get all the rows back in one call. However, you pay a hidden price for this convenience. Let’s look at a pseudo-code implementation of the function. I’ve removed most of the error handling to make the algorithm clearer:

STDAPI

HrQueryAllRows(LPMAPITABLE ptable,

   LPSPropTagArray ptaga,

   LPSRestriction pres,

   LPSSortOrderSet psos,

   LONG crowsMax,

   LPSRowSet FAR *pprows)

{

   HRESULT   hr;

   LPSRowSet prows = NULL;

   UINT      crows = 0;

   LPSRowSet prowsT;


   *pprows = NULL;


   if (ptaga) ptable->SetColumns(ptable, ptaga, TBL_BATCH);

   if (pres)  ptable->Restrict(ptable, pres, TBL_BATCH);

   if (psos)  ptable->SortTable(ptable, psos, TBL_BATCH);


   ptable->SeekRow(ptable, BOOKMARK_BEGINNING,0, NULL);


   if (crowsMax == 0) crowsMax = LONG_MAX;

   for (;;)

   {

      prowsT = NULL;


      // Retrieve some rows. Ask for the limit.

      hr = ptable->QueryRows(ptable, crowsMax, 0, &prowsT);


      // Add the rows just retrieved into the set we're building.

      MergeRowSets(prowsT, &prows);


      if (prowsT->cRows == 0) break;

   }


   *pprows = prows;


   return hr;

}

One thing we notice right off is that except for the magic MergeRowSets function, this code doesn’t do anything special that you couldn’t implement yourself. We’ll talk more about MergeRowSets later. Breaking down the algorithm, we see it first calls the trio of table setup functions: SetColumns, Restrict, and SortTable. Next, we seek to the beginning of the table. Then the fun starts: We read a bunch of rows from the table, then merge those rows with any rows we’ve already retrieved. We keep reading and merging QueryRows doesn’t return any

Why do it this way? Why read in batches? The answer is two part: the first part is that QueryRows doesn’t have a flag to ask for all rows. You have to ask for a fixed number of rows. The second part is that even if QueryRows did have a means to ask for all rows, the number of rows returned is actually determined by the provider. You can ask for 20 rows and the provider can decide, due to underlying constraints, to only return 5. So any routine that wants to read all rows has to operate in batches.

That’s the first pitfall of HrQueryAllRows – working in batches like this means you could end up waiting on the provider to communicate with it’s data store, possibly issuing a large number of network calls in the process.

The second pitfall is the necessary implementation of this MergeRowSets function. Each time it is called, it has to allocate larger and larger blocks of memory to hold the merged row sets. Depending on the table you’re reading, these allocations could easily exceed available memory. Even if they don’t exceed it outright, they can certainly fragment the virtual memory space of the process, lowering the size of the largest free block, which in turn increases the chance that any memory allocation could fail.

This is why the MSDN carries the following caution for HrQueryAllRows:

Tables that are typically small, such as a message store table or a provider table, usually can be safely retrieved with HrQueryAllRows. Tables at risk of being very large, such as a contents table or even a recipients table, should be traversed in subsections using the IMAPITable::QueryRows method.

We see customer’s code here all the time that uses HrQueryAllRows on tables where it should never be used, such as the contents table of an Inbox, or on the Global Address List. This code will work in test environments, where the data sets are small, but will almost certainly fail with MAPI_E_TABLE_TOO_BIG when deployed in production.

Fortunately, eliminating this function is straightforward. The tag array, restriction, and sort order parameters become calls to SetColumns, Restrict, and SortTable, which we see are easy calls to make. Looping calls to QueryRows and then looping over the results is a bit more complex. Here’s a pattern I like to use:

   for (;;)

   {

      hRes = S_OK;


      FreeProws(lpRows);

      lpRows = NULL;

      hRes = lpMAPITable->QueryRows(

         20, // arbitrary value, may be tweaked

         NULL,

         &lpRows);

      if (FAILED(hRes) || !lpRows || !lpRows->cRows) break;


      ULONG iCurRow;

      for (iCurRow = 0; iCurRow<lpRows->cRows; iCurRow++)

      {

         // Do work on lpRows->aRow[iCurRow]

      }

   }

   FreeProws(lpRows);

   lpRows = NULL;

We ask for a batch of rows, fail on any error, process them, and loop. We do NOT check that we got as many rows as we requested, only that we got something. This pattern is much gentler on your virtual memory space. Not only does it not require large memory allocations that will almost certainly fail, most of the memory that is allocated will be the same size, meaning it will most likely occupy the same addresses from one iteration to the next. Hopefully, you’ll be able to incorporate this into your own code and eliminate calls to HrQueryAllRows.

I think this will be the last article to come from James’ post on debugging MAPI (previous posts here, here, and here). This last one bit me when I was trying to gather a UST trace from a customer.

Here’s the deal: The image file name associated with an executable can be different depending on how the process is launched. And Image File Execution Options (IFEO) works on the image file name, not the executable name. To illustrate this, we can rename mfcmapi.exe (my favorite executable, natch) to ThisIsAReallyLongName.exe and run some tests. First, let’s determine the short file name for this file:

D:\MFCMAPI>dir /x ThisIsAReallyLongName.exe
03/16/2009  10:28 AM         1,982,976 THISIS~1.EXE ThisIsAReallyLongName.exe

Next, we launch Procmon and look for anyone opening an IFEO key for a process with “this” in the name. Let’s try launching the process from the command line, using both the long and the short name:

D:\MFCMAPI>ThisIsAReallyLongName.exe
64-bit cmd.exe RegOpenKey
  HKLM\SOFTWARE\Wow6432Node\Microsoft\Windows NT\CurrentVersion\Image File Execution Options\ThisIsAReallyLongName.exe
D:\MFCMAPI>THISIS~1.EXE
64-bit cmd.exe RegOpenKey
  HKLM\SOFTWARE\Wow6432Node\Microsoft\Windows NT\CurrentVersion\Image File Execution Options\ThisIsAReallyLongName.exe

I trimmed and formatted the Procmon output a bit for clarity. The columns are bitness, process name, operation, and key read. So far, no difference in the keys. Let’s see what happens if we ask the debugger to launch the process:

D:\MFCMAPI>windbg ThisIsAReallyLongName.exe
64-bit windbg.exe RegOpenKey
  HKLM\SOFTWARE\Wow6432Node\Microsoft\Windows NT\CurrentVersion\Image File Execution Options\ThisIsAReallyLongName.exe
32-bit ThisIsAReallyLongName.exe RegOpenKey
  HKLM\SOFTWARE\Microsoft\WINDOWS NT\CURRENTVERSION\Image File Execution Options\ThisIsAReallyLongName.exe
D:\MFCMAPI>windbg THISIS~1.EXE
64-bit windbg.exe RegOpenKey
  HKLM\SOFTWARE\Wow6432Node\Microsoft\Windows NT\CurrentVersion\Image File Execution Options\THISIS~1.EXE
32-bit THISIS~1.EXE RegOpenKey
  HKLM\SOFTWARE\Microsoft\WINDOWS NT\CURRENTVERSION\Image File Execution Options\THISIS~1.EXE

The first thing we notice is now both the launching process and the launched process are reading IFEO keys. Next, we notice the 64/32 bit difference showing up in the paths. But the biggest difference is one is looking for a key named “ThisIsAReallyLongName.exe” while the other looks for “THISIS~1.EXE”.

So maybe this is a quirk of the debugger? Let’s try running the app from Start Run:

Start\Run: d:\mfcmapi\ThisIsAReallyLongName.exe
64-bit Explorer.EXE RegOpenKey
  HKLM\SOFTWARE\Wow6432Node\Microsoft\Windows NT\CurrentVersion\Image File Execution Options\ThisIsAReallyLongName.exe
Start\Run: d:\mfcmapi\thisis~1.exe
64-bit Explorer.EXE RegOpenKey
  HKLM\SOFTWARE\Wow6432Node\Microsoft\Windows NT\CurrentVersion\Image File Execution Options\thisis~1.exe

We’re back to one process reading the keys, but we still see that the key name depends on whether we used the long or short name for the file.

So – the upshot here, combined with the 32/64 bit issue from before, is when setting IFEO options to enable UST (or anything else IFEO is used for), you potentially need to set the options in 4 places, depending on the bitness of the process, whether or not a long file name is involved, and who launched the process.

The March 2009 Release (build 6.0.0.1012) is live: http://mfcmapi.codeplex.com. Note the new URL – the old one still works.

At the urging of Jason, I’ve added parsing of entry IDs per the protocol docs.

Here's a change list - see the Issue Tracker on Codeplex for more details, or look at the code:

• Super ultra cool entry ID parsing
• Fixed slow dialogs
• Fixed overnight crashes
• Added Fast Shutdown (note – MFCMAPI won’t call Fast Shutdown normally – only if you ask it to)
• Added support for fiddling with PST paths and setting passwords

Enjoy.

Digging more into lessons learned from James’ blog on analyzing memory usage (my first two articles are here and here). Today we take a side trip into 64 vs. 32 bit. While we were working on this issue, I decided to get some UST enabled dumps of MFCMAPI so I could compare a known scenario to the customer’s unknown scenario (a great diagnostic technique). However, no matter what settings I specified in gflags, when I attached the debugger, MFCMAPI didn’t have UST enabled!

Let’s look at how gflags works. When you run the command “gflags /i mfcmapi.exe +ust”, some registry keys are created here:

HKLM\SOFTWARE\Microsoft\Windows NT\CurrentVersion\Image File Execution Options

Specifically, the key mfcmapi.exe is created and some values are set under it. When you launch a process, the OS matches looks for this registry key, reads the values, and uses them in setting up the process.

Of course, this didn’t work for me, so I ran Procmon to see what key the OS was looking for. Procmon showed the OS was looking here:

HKLM\SOFTWARE\Wow6432Node\Microsoft\Windows NT\CurrentVersion\Image File Execution Options

The key difference of course being the Wow6432Node. It turns out I had both the 32 bit and 64 bit debugger packages installed on this machine, and each comes with it’s own version of gflags. On a 32 bit machine, the 32 bit gflags sets the normal, non-wow64 key. But on a 64 bit OS, the 32 bit version of gflags gets redirected to Wow6432Node. The 64 bit version of gflags, of course, sets the non-wow64 key.

The trick here is I had run the 64 bit gflags, which set the non-wow64 key, but the MFCMAPI process was looking under  Wow6432Node. Once I ran the 32 bit version of gflags, UST worked quite nicely. Problem solved.

Except – when I launched MFCMAPI from the 64 bit debugger a strange thing happened. The OS read from the non-wow64 node. If I’ve only run the 32 bit gflags I don’t get UST. The explanation is spelled out in Mithun’s post on Image File Execution Options (IFEO)– where the OS looks depends on the bitness of the process that called CreateProcess, not the bitness of the process being launched!

So – if you’re giving someone instructions to gather dumps for you, and you want UST (or any other IFEO setting), to be safe you’re best off having them set reg keys in both places. Then it won’t matter how the process was launched, or what the bitness is.

Next: UST and long file names.

Continuing our look at lessons learned from James’ article on the MAPI memory leak, we look at the memory that James recognized as MAPI properties. How did he figure this out? As a refresher, here’s what the memory looked like:

0:000> !heap -p -a 0372e598 
    address 0372e598 found in
    _HEAP @ 36f0000
      HEAP_ENTRY Size Prev Flags    UserPtr UserSize - state
        0372e598 0022 0000  [07]   0372e5a0    000f8 - (busy)
          ? 3rdpartydll+1
        Trace: 7dfe
0:000> dc 0372e598 lf8/4+2+4
0372e598  000d0022 001807d6 10000001 03707d50  "...........P}p.
0372e5a8  0fff0102 00000000 00000018 203d4590  .............E= 
0372e5b8  001a001e 00000000 1f867038 00000000  ........8p......
0372e5c8  30070040 00000000 500075a0 01c8cfa5  @..0.....u.P....
0372e5d8  300b0102 00000000 00000010 14463e00  ...0.........>F.
0372e5e8  0037001f 00000000 204a2d48 00000000  ..7.....H-J ....
0372e5f8  0037001e 00000000 204a7170 00000000  ..7.....pqJ ....
0372e608  003d001f 00000000 204b6e00 00000000  ..=......nK ....
0372e618  003d001e 00000000 204b7848 00000000  ..=.....HxK ....
0372e628  0e060040 00000000 4a1c9600 01c8cfa5  @..........J....
0372e638  00390040 00000000 55de88e0 01c8cfa5  @.9........U....
0372e648  1035001e 00000000 18686170 00000000  ..5.....pah.....
0372e658  0c1f001f 00000000 193c8340 00000000  ........@.<.....
0372e668  0c1f001e 00000000 03707d58 00000000  ........X}p.....
0372e678  00170003 00000000 00000001 00000000  ................
0372e688  0e1b000b 00000000 00000001 00000000  ................
0372e698  abababab abababab 00007dfe 00000000  .........}......

Recall that James and I discussed how the !heap extension tries running dps against the beginning of the user porion of the memory allocation (0x0373e5a0 in this case) on the hopes it might point to an object vtable. In this case, it does point into a module, but it’s not a vtable. How do we know? Our first big clue is the address, 10000001, has very few bits in it. Two to be exact. Whenever you see a 32 bit value in memory that has only a handful of bits set in it, there’s a really good chance it’s a flag. Our second clue comes when we run dps against the address, we see that if it were a function pointer, it’s pointing at a different module, which you shouldn’t see in a vtable:

0:000> dps 10000001 l1
10000001  0300905a MSOINTL+0x75905a

Our third clue, and, for me, the nail in the coffin, is that 10000001 isn’t a multiple of 4. I have never seen a vtable that wasn’t 4 byte aligned.

So if this memory isn’t an object, what is it? If you spend some time allocating memory with MAPIAllocateBuffer and MAPIAllocateMore, then looking at the corresponding heap allocations, you’ll see that those functions always allocate 8 bytes more than you ask for. If you look at those extra 8 bytes, you’ll probably notice that allocations made by MAPIAllocateBuffer always start with the 4 bytes 10000001, and allocations made by MAPIAllocateMore always start with the 4 bytes 20000001. The second 4 bytes on these allocations look like pointers into the heap. We can walk these pointers and see the chain of allocations that MAPIFreeBuffer will walk when it is asked to free this memory. Since the pointer to the next entry happens to be in the same offset as a Blink in the LIST_ENTRY structure, we can abuse the dl (Display Linked List) command to output our list:

0:000> dlb 0372e5a0 f 2
0372e5a0  10000001 03707d50
03707d50  20000001 193c8338
193c8338  20000001 18686168
18686168  20000001 204b7840
204b7840  20000001 204b6df8
204b6df8  20000001 204a7168
204a7168  20000001 204a2d40
204a2d40  20000001 14463df8
14463df8  20000001 1f867030
1f867030  20000001 203d4588
203d4588  20000001 00000000

So – that’s an interesting digression, but we still haven’t figured out what this memory is. From the caller’s perspective, the allocation began at 0372e5a8 (8 more than the address MAPI got from the heap), and appears to follow a 10 byte pattern from there. Notice that the entries in the first column tend to end in 0102, 001E, 0040, 0003, etc. If you’ve been working with MAPI for a while, you’ll recognize these as PT_BINARY, PT_STRING8, PT_SYSTIME, and PT_LONG. So that first column consists of property tags! Do we know of any MAPI structures that are 0x10 bytes long and start with a property tag? Turns out we do:

0:000> dt -v _SPropValue
mfcmapi!_SPropValue
struct _SPropValue, 3 elements, 0x10 bytes
   +0x000 ulPropTag        : Uint4B
   +0x004 dwAlignPad       : Uint4B
   +0x008 Value            : union _PV, 28 elements, 0x8 bytes

And if we try casting this memory as _SPropValue, we see everything lines up quite nicely, so this must be an array of type _SPropValue. The output is rather long – I’ll leave it as an exercise for the reader. Remember to use –a and –r!

Next: a brief look at UST and 64 bit machines.

James wrote up a good article on analyzing a MAPI memory leak using user mode stack tracing. I wanted to highlight some points he made. Let’s look at some !heap output from one of my recent cases (using only public symbols here):

0:000> !heap -p -a 03fbec28    
    address 03fbec28 found in
    _HEAP @ 3f90000
      HEAP_ENTRY Size Prev Flags    UserPtr UserSize - state
        03fbec20 0021 0000  [07]   03fbec28    000f0 - (busy)
          ? EMSMDB32!MSProviderInit+1d27a
        Trace: 1922
        7c8531e4 ntdll!RtlAllocateHeapSlowly+0x00000041
        7c83d97a ntdll!RtlAllocateHeap+0x00000e9f
        35b732f4 EMSMDB32!MSProviderInit+0x0000186a

The line starting with the ? is the output of dps (Display Words and Symbols) against the start of the allocation. Basically, it’s saying “suppose this was a pointer – what does it point to?”. The reason it does this is in case this allocation happens to be an object. Objects are usually laid out in memory with pointers to the object’s virtual tables (vtable) at the beginning. Even without symbols, we can see that this in this case, it *could* be an object. Let’s take a closer look:

0:000> dps 03fbec28 l3
03fbec28  35b8ed04 EMSMDB32!MSProviderInit+0x1d27a
03fbec2c  35b728b8 EMSMDB32!MSProviderInit+0xe2e
03fbec30  00000001
0:000> dps 35b8ed04 l3
35b8ed04  35b90861 EMSMDB32!MSProviderInit+0x1edd7
35b8ed08  e958026a
35b8ed0c  ffff4140
0:000> dps 35b728b8 l3
35b728b8  35b90839 EMSMDB32!MSProviderInit+0x1edaf
35b728bc  35b7d7eb EMSMDB32!MSProviderInit+0xbd61
35b728c0  35b7d91f EMSMDB32!MSProviderInit+0xbe95

First, we run dps against the allocation, and see two possible vtables. If they are indeed vtables, dps against what they point to should also be code within emsmdb32. And we see that it is – the first points to a vtable with a single function, and the second points to a vtable with several functions. We can carry this further by unassembling the possible functions (such as 35b90861 or 35b90839) to see that the output does resemble a function header. Assuming we’re debugging our own process, we can look further down the stack from the !heap command and see that this memory was allocated in response to an OpenEntry call for a message, and conclude this is a message object.

Next time: we’ll take a look at flags and recognizing MAPI properties in memory.

The PST provider in Outlook 2007 supports Fast Shutdown. The Wrapped PST sample is built by wrapping objects from the PST provider. Ergo, if a provider built on the Wrapped PST model does not intercept queries for IID_IMAPIClientShutdown, it supports Fast Shutdown.

In other words, if your Wrapped PST based provider has problems with Fast Shutdown, you need to implement IMAPIClientShutdown and return MAPI_E_NO_SUPPORT from QueryFastShutdown. And if your Wrapped PST base provider is OK with Fast Shutdown, but you need to know when it’s happening, you need to implement IMAPIClientShutdown and wrap the PST’s implementation.

Right now, the Sample Transport Provider, MrXP, and the Sample Address Book Provider, SABP, do not implement the Fast Shutdown client interface at all, so if they are installed, Outlook will not use Fast Shutdown.

So – one of my teammates tells me that if he leaves MFCMAPI running overnight, it has usually crashed by the time he comes in the next morning. We got a few dumps, but they were inconclusive since the stacks were completely different every time. Since we didn’t know what was going on, we started paying attention to when and where the problem happened. We noted the following:

• He usually runs MFCMAPI from a tools share on one of my machines.
• If he copies MFCMAPI locally and runs it overnight, it never crashes.
• If he tries running some other tools from the same share, he can cause them to crash overnight as well.
• Another engineer who overheard us discussing the problem was also able to reproduce it.

Armed with this information, I decided to look at the dumps again. The exception thrown in each was 0xC0000006, STATUS_IN_PAGE_ERROR. Ok – so that’s explains things – maybe some network hiccup causes us to lose the connection to the original executable, then the next time the process needs to load a page of memory it can’t find it?

For a while, I thought this was the end of the investigation – there’s no way MFCMAPI can control network hiccups, right? Then I stumbled across this linker option:

/SWAPRUN

Basically, when this option is set, the OS will copy the whole binary image to a local swap file before running it. We set the “Swap Run From Network” switch on a test build, and he hasn’t been able to reproduce the crash again. If you’re in to manually editing your .vcproj file, this is the equivalent of adding the line

SwapRunFromNet=”true”

to the “VCLinkerTool” section of your project’s configuration.

The next version of MFCMAPI will have this option enabled for all configurations.

I’m repeating myself – I did use a variation on this title before. In this case, suppose you’re using a custom transport provider, like MrXP, and you’re delivering to a regular (not wrapped) PST. In Outlook 2003, this worked great. If you had rules set up, they all got fired on delivery. In Outlook 2007 though, this stopped working.

The basic design of a transport provider is this:
1 - Outlook's protocol handler has a function which will get messages from the transport.
2 - The transport provider implements a function called StartMessage. This function takes a new LPMESSAGE as a parameter. The transport provider is expected to fill out this message with details, then save it.
3 - When StartMessage returns, the protocol handler calls a function to handle firing the new mail notifications
4 – Outlook is listening for these notifications. One listener is responsible for determining if rules should be run on the message or if the message should enter the item prop pipeline.

Remember from our work with the wrapped PST that the PST is an Item Proc store, so the listener will never run rules directly on the message. So the only way the message will get rules fired on it is if it enters the item proc pipeline. And the only way for the message to enter the item proc pipeline is for it to have ITEMPROC_FORCE and NON_EMS_XP_SAVE set during the SaveChanges call.

Great, except it doesn’t work. Suppose you go into MrXP and add both of those flags to SaveChanges. You’ll see no change in behavior. That’s where the February update comes in. It turns out that between the transport calling SaveChanges and the save actually happening in the PST, there was some code validating the flags passed in. This code had the side effect of stripping the ITEMPROC_FORCE and NON_EMS_XP_SAVE flags. The hotfix corrects this code to allow the flags through.

I’ve updated MrXP up on CodePlex to start passing the flags. With the updated MrXP and with the February update applied, you should see rules start working again.

I noticed recently that one on of my machines, whenever I ran MFCMAPI and displayed one of my CEditor dialogs, the whole machine froze for 1 to several minutes. I figured this would be a fun opportunity to practice my kernel debugging skills and share what I learned.

A bit about my setup: I keep two physical machines in my office. On the larger machine, I run Hyper-V Server 2008. This headless box sits in the corner and hosts all my VMs, including the VM where I run Outlook and other day-to-day case and labor tracking tools on Vista. The smaller machine, running Windows Server 2008, is my file server and my primary development and debugging desktop. Both machines are x64 and many of my VMs are as well.

The machine where I saw the hang was my tools VM, so I figured I’d try a remote VM kernel debug from my development machine. I haven’t seen a good set of instructions for doing this with these operating systems, so I had to crib bits and pieces from various sources. The first step is to enable kernel debugging on the target machine. On Vista, this means using BcdEdit:

1. Open an administrative command prompt.
2. Run bcdedit /debug on. This enables kernel debugging using the default setting of COM1, which is what we need.

Next, we have to map a named pipe on the Hyper-V server to COM 1 on the VM. This named pipe is what we’ll connect to. The process is described here:

1. Open Hyper-V Manager, select the VM to be debugged, and open Settings
2. Select COM 1, choose Named pipe, and enter a name for the pipe. The name doesn’t really matter. I chose debug.

Now’s a good time to reboot the VM so both settings take effect.

If we try to skip ahead to the remote debug at this point, we won’t be able to connect. The reason is the firewall on the Hyper-V Server is going to block our attempts to hook up to the named pipe. Named pipes use the file server ports 139 and 445, so we just need to open those ports:

1. This is tricky since Hyper-V server is command line only. We can open a Remote Desktop to the server, or hookup a keyboard and monitor and log on, but either way all we’ll have is the command line.
2. Run the following two commands to open ports 139 and 445:

   netsh advfirewall firewall add rule name="File Server (TCP 139)" localport=139 dir=in action=allow protocol=tcp

   netsh advfirewall firewall add rule name="File Server (TCP 445)" localport=445 dir=in action=allow protocol=tcp

Now we’re ready to remote debug.

The following command, run from our remote machine, attaches the debugger (hyperboo is the name of my Hyper-V server, and Debug is the named pipe we attached to COM 1 on the target VM):

Note that the debugger doesn't break in right away - it just sits there saying "Waiting to reconnect...". We run through the steps to hang the machine (start MFCMAPI, open Other/Options will do), then switch over to the debugger and hit Ctrl+Break to attach. Now the fun part begins. We point at the public NT symbols, then append the path where MFCMAPI's symbols are located:

1. .sympath srv*c:\symbols*http://msdl.microsoft.com/download/symbols
2. .sympath+ c:\mfcmapi\Release
3. .reload

We run !locks to see what's holding up the system. This command runs for a very long time as it scans memory for every lock:

1: kd> !locks
**** DUMP OF ALL RESOURCE OBJECTS ****
KD: Scanning for held locks...
Resource @ 0xfffffa80024ac0d0    Shared 1 owning threads
     Threads: fffffa80018cb290-01<*> 
KD: Scanning for held locks....................... 

Resource @ 0xfffffa8002423ab0    Exclusively owned
    Contention Count = 3017959
    NumberOfExclusiveWaiters = 8
     Threads: fffffa800255a3c0-01<*> 
     Threads Waiting On Exclusive Access:
              fffffa8003e57bb0       fffffa8001f326b0       fffffa800399fbb0       fffffa800356a8c0       
              fffffa8003ab5520       fffffa8003f1cbb0       fffffa800348abb0       fffffa80033a9060       

KD: Scanning for held locks. 

Resource @ 0xfffffa800324d8c0    Exclusively owned
    Contention Count = 538
     Threads: fffffa8003dd69f0-01<*> 
KD: Scanning for held locks. 

Resource @ 0xfffffa800250f3b0    Exclusively owned
    Contention Count = 266255
    NumberOfExclusiveWaiters = 2
     Threads: fffffa8003dd69f0-01<*> 
     Threads Waiting On Exclusive Access:
              fffffa800255a3c0       fffffa80032c0390       

KD: Scanning for held 

locks...
13422 total locks, 4 locks currently held 

We find that lock 0xfffffa800324d8c0 has a contention count of 538, meaning it is blocking 538 threads! We then use the -v option to get more information on the lock:

1: kd> !locks -v 0xfffffa800324d8c0 

Resource @ 0xfffffa800324d8c0    Exclusively owned
    Contention Count = 538
     Threads: fffffa8003dd69f0-01<*> 

     THREAD fffffa8003dd69f0  Cid 134c.11ac  Teb: 000000007efdb000
        Win32Thread: fffff900c2dfa010 RUNNING on processor 0
     Not impersonating
     DeviceMap                 fffff8800ef7d720
     Owning Process            fffffa8003afaab0       Image:         MFCMapi.exe
     Attached Process          N/A            Image:         N/A
     Wait Start TickCount      6762745        Ticks: 28 (0:00:00:00.437)
     Context Switch Count      758                 LargeStack
     UserTime                  00:00:00.828
     KernelTime                00:00:04.281
     Win32 Start Address 0x0000000000eb318b
     Stack Init fffffa60035ecdb0 Current fffffa60035ebd30
     Base fffffa60035ed000 Limit fffffa60035e2000 Call 0
     Priority 8 BasePriority 8 PriorityDecrement 0 IoPriority 2 PagePriority 5
     Child-SP          RetAddr           Call Site
     fffffa60`035ec0c8 fffff960`000c5ba8 win32k!vAlphaPerPixelOnly+0x36
     fffffa60`035ec0d0 fffff960`000c57a3 win32k!AlphaScanLineBlend+0x304
     fffffa60`035ec190 fffff960`00259509 win32k!EngAlphaBlend+0x4f3
     fffffa60`035ec440 fffff960`00259a2a win32k!NtGdiUpdateTransform+0x1075
     fffffa60`035ec4f0 fffff960`00259b47 win32k!NtGdiUpdateTransform+0x1596
     fffffa60`035ec610 fffff960`00259d05 win32k!EngNineGrid+0xb3
     fffffa60`035ec6b0 fffff960`0025a17c win32k!EngDrawStream+0x1a1
     fffffa60`035ec770 fffff960`0025ab35 win32k!NtGdiDrawStreamInternal+0x440
     fffffa60`035ec820 fffff960`002737fc win32k!GreDrawStream+0x98d
     fffffa60`035ecac0 fffff800`0189cdf3 win32k!NtGdiDrawStream+0x9c
     fffffa60`035ecc20 00000000`75b8a59a nt!KiSystemServiceCopyEnd+0x13

1 total locks, 1 locks currently held

Note that MFCMAPI.exe holds this lock, so we're on the right track. We use .thread to switch our context to thread fffffa8003dd69f0, using the /P and /r switches to force the debugger to translate page table entries and reload symbols for the implicit process:

1: kd> .thread /P /r fffffa8003dd69f0
Implicit thread is now fffffa80`03dd69f0
Implicit process is now fffffa80`03afaab0
.cache forcedecodeptes done
Loading User Symbols
.....
Loading Wow64 Symbols
......................................

Now - we're stuck. Normally, we'd expect to see the user mode stack below the switch to kernel mode. But we don't see it here. Instead, we see the wow64 translation layer, since we're running a 32 bit process on a 64 bit processor:

1: kd> kL
  *** Stack trace for last set context - .thread/.cxr resets it
Child-SP          RetAddr           Call Site
fffffa60`035ec0c8 fffff960`000c5ba8 win32k!vAlphaPerPixelOnly+0x36
fffffa60`035ec0d0 fffff960`000c57a3 win32k!AlphaScanLineBlend+0x304
fffffa60`035ec190 fffff960`00259509 win32k!EngAlphaBlend+0x4f3
fffffa60`035ec440 fffff960`00259a2a win32k!NtGdiUpdateTransform+0x1075
fffffa60`035ec4f0 fffff960`00259b47 win32k!NtGdiUpdateTransform+0x1596
fffffa60`035ec610 fffff960`00259d05 win32k!EngNineGrid+0xb3
fffffa60`035ec6b0 fffff960`0025a17c win32k!EngDrawStream+0x1a1
fffffa60`035ec770 fffff960`0025ab35 win32k!NtGdiDrawStreamInternal+0x440
fffffa60`035ec820 fffff960`002737fc win32k!GreDrawStream+0x98d
fffffa60`035ecac0 fffff800`0189cdf3 win32k!NtGdiDrawStream+0x9c
fffffa60`035ecac0 fffff800`0189cdf3 win32k!NtGdiDrawStream+0x9c
fffffa60`035ecc20 00000000`75b8a59a nt!KiSystemServiceCopyEnd+0x13
00000000`001ddda8 00000000`75d7a996 wow64win!NtGdiDrawStream+0xa
00000000`001dddb0 00000000`75d63688 wow64!Wow64SystemServiceEx+0xca
00000000`001de660 00000000`75d7ab46 wow64cpu!ServiceNoTurbo+0x28
00000000`001de6f0 00000000`75d7a14c wow64!RunCpuSimulation+0xa
00000000`001de720 00000000`77ac52d3 wow64!Wow64LdrpInitialize+0x4b4
00000000`001dec80 00000000`77ac5363 ntdll!LdrpInitializeProcess+0x14ac
00000000`001def30 00000000`77ab85ce ntdll! ?? ::FNODOBFM::`string'+0x1ff19
00000000`001defe0 00000000`00000000 ntdll!LdrInitializeThunk+0xe

So we try .thread again, this time passing the /w switch to change to the 32 bit context:

1: kd> .thread /P /r /w fffffa8003dd69f0
Implicit thread is now fffffa80`03dd69f0
Implicit process is now fffffa80`03afaab0
.cache forcedecodeptes done
Loading User Symbols
.....
Loading Wow64 Symbols
......................................
The context is partially valid. Only x86 user-mode context is available.
x86 context set
0: kd:x86> kbL 1d
ChildEBP          RetAddr           Args to Child                                         
0040e05c 7732891e e8011177 00000060 0040e1e4 GDI32!NtGdiDrawStream+0x15
0040e160 73a6276e e8011177 00000060 0040e1e4 GDI32!GdiDrawStream+0x436
0040e3dc 73a624f9 00486ff8 004856c8 00000001 uxtheme!CImageFile::DrawBackgroundDS+0x439
0040e458 73a623a0 00486ff8 02900968 e8011177 uxtheme!CImageFile::DrawImageInfo+0x1dd
0040e4a8 73a627f8 02900968 e8011177 00000002 uxtheme!CImageFile::DrawBackground+0x45
0040e4f8 73a64946 02900968 e8011177 00000001 uxtheme!DrawThemeBackground+0xcc
0040e590 73a6789b 34011934 0292725c e8011177 uxtheme!CThemeWnd::NcPaintCaption+0x11a
0040e5b0 73a62ea0 0292725c 00000000 00000000 uxtheme!OnDwpSetIcon+0x6b
0040e604 73a60e74 00000000 00000000 00000001 uxtheme!_ThemeDefWindowProc+0x15d
0040e620 777dc18b 001d02de 00000080 00000001 uxtheme!ThemeDefWindowProcA+0x18
0040e668 777f7fec 001d02de 00000080 00000001 USER32!DefWindowProcA+0x68
0040e680 777e6050 0110d2f0 00000000 00000080 USER32!DefWindowProcWorker+0x27
0040e6c8 777f7fe3 0110d2f0 00000000 00000080 USER32!DefDlgProcWorker+0x7f7
0040e6e8 777d8807 001d02de 00000080 00000001 USER32!DefDlgProcA+0x29
0040e714 777d8962 77ca3db0 001d02de 00000080 USER32!InternalCallWinProc+0x23
0040e78c 777dc62c 00000000 77ca3db0 001d02de USER32!UserCallWinProcCheckWow+0x109
0040e7c4 777dd163 77ca3db0 001d02de 00000080 USER32!CallWindowProcAorW+0xa9
0040e7e4 00e75ed8 77ca3db0 001d02de 00000080 USER32!CallWindowProcA+0x1b
0040e804 00e76074 00000080 00000001 1ee70f3d MFCMapi!CWnd::DefWindowProcA+0x44
0040e820 00e08cb2 00000080 00000001 1ee70f3d MFCMapi!CWnd::WindowProc+0x3b
0040e850 00e79210 00000080 00000001 1ee70f3d MFCMapi!CEditor::WindowProc+0x222
0040e8b8 00e7929f 00000000 001d02de 00000080 MFCMapi!AfxCallWndProc+0x9a
0040e8d8 777d8807 001d02de 00000080 00000001 MFCMapi!AfxWndProc+0x36
0040e904 777d8962 00e79269 001d02de 00000080 USER32!InternalCallWinProc+0x23
0040e97c 777dc4b6 00000000 00e79269 001d02de USER32!UserCallWinProcCheckWow+0x109
0040e9c0 777deae2 0110d2f0 00000000 00e79269 USER32!SendMessageWorker+0x55b
0040e9e4 00e08f87 001d02de 00000080 00000001 USER32!SendMessageA+0x7f
0040edbc 00e74666 0040edf0 777d8807 001d02de MFCMapi!CEditor::OnInitDialog+0x167
0040edc4 777d8807 001d02de 00000110 001d02de MFCMapi!AfxDlgProc+0x31

Now we can piece together what happened. Down in the kernel layer, we see we’re doing something with graphics.Scanning back up the user mode stack, we find that MFCMapi!CEditor::OnInitDialog has called SendMessage, which is then handled by uxtheme. The message we're passing is 0x80, which is WM_SETICON. Back in the MFCMAPI code, we see we're on the line:

	SetIcon(m_hIcon, TRUE);			// Set big icon

Now it's all starting to come together. In the process of setting up out dialog, we call WM_SETICON twice, once to set the big icon and once to set the small icon. But this is a dialog, so the big icon isn't needed at all. When we remove this call, and just leave the call to set the small icon, dialogs open rapidly! This fix will be in the next release of MFCMAPI.

We learned three things in this process. First – setting up a live kernel debug to a Hyper-V VM isn’t all that hard once you know how to do it. Second, it is possible for ordinary user mode operations to hang in kernel mode. And last, copying and pasting code around without understanding what it does is never a good idea.