Exceptions

Threads

Multithread applications have multiple threads. Each thread represents a path of execution and owns resources, such as stack, thread local storage, local variables, and thread environment block. Proper use of threads can enhance the performance of an application, whereas poor implementation can hinder performance.

Creating threads is not difficult. Managing threads is the real challenge. Thread synchronization, which is the management of threads, entails several activities, including preventing race conditions and controlling access to resources. Threads are like children that require corralling.

Improperly implemented threads can lead to a high utilization or low utilization condition. High utilization is characterized by one or more threads consuming at or near 100-percent CPU utilization. Other threads are starved for time, which makes the application appear to hang or behave incorrectly. Low utilization is the reverse. The process and contained threads are receiving minimal or no CPU usage.

There are two primary reasons for high utilization:

• Threads in tight loop that usurp all CPU resources

• Active high-priority threads that prevent lower-priority threads from receiving attention from the CPU

There is an assortment of reasons for low utilization:

• Threads waiting for resources that never become available. Threads in that state are suspended indefinitely and receive little CPU time.

• Threads mutually blocked on each other. This deadlock suspends both threads indefinitely, and both receive little CPU time.

• A low-priority thread in a sea of high priority threads has little opportunity to sail. It is accorded minimal CPU time.

• Threads with an erroneously high suspend counts are not resumed when planned. For this reason, the thread continues to receive no CPU time.

The previous items highlight some of the reasons for high and low utilization. There are plenty more. However, high and low utilization are not the only issues. Multithreaded and simultaneous access to non-thread-safe resources is another cause for application failures. Actually, the list of potential transgressions from multithreading is almost endless. Threading is fertile ground for debugging.

For brevity, this section focuses on monitors and mutexes. Synchronization problems from semaphores, events, and reader-writer locks are not discussed. Monitors synchronize access to a single resource. The resource could be an object, data structure, or even an algorithm—anything that requires singular access. Monitors are limited to synchronizing threads within the same process. A mutex also synchronizes access to a single resource. However, mutexes have additional power and flexibility. For example, mutexes can synchronize threads across processes.

Monitors are the most frequently used synchronization device. For that reason, the CLR tracks monitors for efficient access. Instances of objects have an additional field called the syncblock index, which is an index into the syncblock table where monitors are tracked. The syncblock index of an object defaults to zero. When an object is assigned to a monitor, the syncblock index is updated to point to an entry in the syncblock table. Otherwise, the syncblock index remains 0. In .NET 2.0, a syncblock entry is not created for every object associated with a monitor. If the monitor is not already associated with a syncblock, a thinlock is created instead. The command !syncblk -all lists the outstanding syncblocks, !dumpheap -thinlock reports the thinlocks.

Markers for thread synchronization can be found on the call stack. Finding AwareLock.Enter, WaitHandle.WaitAll, and WaitForMultipleObjects in the call stack are indications of thread synchronization activity.

• AwareLock.Enter This method is called when an object is bound to a monitor. If the following breakpoint is hit, that thread is entering a monitor:

   bp mscorwks!AwareLock::Enter 

• WaitHandle.WaitAll Except for monitors, most synchronization objects in .NET are derived from the WaitHandle class. Look for method calls from this class on the managed call stack, including WaitOne and WaitAll, as a sign of pending synchronization.

• WaitForMultipleObjects Most waits on synchronization objects, managed or unmanaged, dissolve in a WaitForMultipleObjects API, which is the workhorse of thread synchronization. This is the syntax of the WaitForMultipleObjects API:

  • DWORD WaitForMultipleObjects(DWORD nCount, const HANDLE*

  • lphandles, BOOL bWaitAll, DWORD dwMilliseconds)

Threads Commands

The first step for debugging threads in WinDbg and SOS is to use the thread commands. In WinDbg, the tilde (~) is the thread command; in SOS, the command is !threads.

This is sample output from the WinDbg thread command:

 0:000> ~ . 0  Id: f7c.f80 Suspend: 1 Teb: 7ffdd000 Unfrozen    1  Id: f7c.f9c Suspend: 1 Teb: 7ffdc000 Unfrozen    2  Id: f7c.fa0 Suspend: 1 Teb: 7ffdb000 Unfrozen    3  Id: f7c.fa4 Suspend: 1 Teb: 7ffda000 Unfrozen    4  Id: f7c.de0 Suspend: 1 Teb: 7ffd9000 Unfrozen 

Listed in order, the columns are thread number, process identifier, thread identifier, suspend count, address of thread environment block, and status of the thread.

Here is output from the SOS threads command:

 0:000> !threads ThreadCount: 4 UnstartedThread: 1 BackgroundThread: 1 PendingThread: 0 DeadThread: 0 Hosted Runtime: no                                     PreEmptive   GC Alloc             Lock        ID OSID ThreadOBJ  State     GC       Context         Domain   Count APT Exception    0    1  f80 001501f8    6020 Disabled 013c2cf0:013c32bc 001483a8     0 STA    2    2  fa0 00153e40    b220 Enabled  00000000:00000000 001483a8     0 MTA (Finalizer)    4    3  de0 0018b898    b020 Disabled 013b4cdc:013b52bc 001483a8     2 MTA XXXX    4    0 0018e750    9400 Enabled  00000000:00000000 001483a8     0 Ukn 

The information on managed threads includes the following:

• ID Unmanaged thread number

• OSID Managed thread number

• ThreadObject Address of related thread object

• State State of the thread

• Preemptive GC Whether a thread can be preempted for garbage collection

• AppDomain Address of the AppDomain that hosts the thread

• Lock Count Lock count

• APT Apartment model

Threads Walkthrough

Multithread capabilities have been added to the Store application. Two buttons have been added. The Enumerate button writes the transactions to the forward.txt file. The Reverse Enumerate button writes the transactions, in reverse order, to the reverse.txt file. Each button handler creates and starts a thread to accomplish the reporting tasks.

1. Close all instances of the Store application.

2. Start the Store program and add three transactions. Click the Enumerate button to write the transactions to the forward.txt file. Close the Store program and open the forward.txt file, which is found to be empty. It should contain three transactions!

3. Try again. Reopen the Store application and add three transactions. However, upon clicking the Enumerate button an unhandled exception occurs. What is the problem? You need to investigate.

4. Start the Store application yet again. Retrieve the process identifier using the tlist command. However, notice that there are two Store applications running. Apparently a previous version is still running in the background. This kind of problem is typical of a hung thread, which keeps an application alive after the user closes the main window.

5. Use ADPlus to obtain a dump of the earlier Store application. This is the command:

    adplus -hang -o c:\dumps -p 2696 

6. Open the resulting dump file in WinDbg.

7. Load the SOS debugger extension and list out the managed threads. For readability, some of the columns have been removed from this listing:

    0:000> .load sos 0:000> !threads ThreadCount: 3 UnstartedThread: 0 BackgroundThread: 2 PendingThread: 0 DeadThread: 0 Hosted Runtime: no                                              PreEmptive   GC Alloc            Lock              ID OSID ThreadOBJ     State     GC       Context       Domain   Count         0     1  a90 001501f8    2016220 Enabled  013dbe2c:013dc990 001483a8     0         2     2  9c8 00153e40       b220 Enabled  00000000:00000000 001483a8     0         4     3  3e0 00190718       b020 Disabled 013d63b0:013d6990 001483a8     2 

Thread 4 seems to be the culprit. It is the only thread with a positive lock count. What is the thread waiting for? This question is answered with the !dumpheap -thinlock command:

 0:000> !dumpheap -thinlock  Address       MT     Size 01392440 00d443e8       24      ThinLock owner 3 (00199a78) Recursive 0 01392468 790fa098       12      ThinLock owner 3 (00199a78) Recursive 0 

From the preceding listing, both thinlocks are owned by Thread 4. The address of the Thread 4 object is 0x00199a78, which could be nested locks. Dump the method tables of the thinlocks to uncover what Thread 4 is waiting for:

 0:000> !dumpmt 00d443e8 EEClass: 79126bb0 Module: 790c2000 Name: System.Collections.Generic.List`1[[Store.Item, Store]] mdToken: 02000287 (C:\WINDOWS\assembly\GAC_32\mscorlib\2.0.0.0__b77a5c561934e089\mscorlib.dll) BaseSize: 0x18 ComponentSize: 0x0 Number of IFaces in IFaceMap: 6 Slots in VTable: 30 0:000> !dumpmt 790fa098 EEClass: 790fa034 Module: 790c2000 Name: System.Object mdToken: 02000002 (C:\WINDOWS\assembly\GAC_32\mscorlib\2.0.0.0__b77a5c561934e089\mscorlib.dll) BaseSize: 0xc ComponentSize: 0x0 Number of IFaces in IFaceMap: 0 Slots in VTable: 14 

What is known? When the program hung, Thread 4 had outstanding locks on an Item and Object instance. No other thread is holding a lock, which narrows the problem to Thread 4. Here is the source code for Thread 4:

 private void Forward() {     lock (items)     {         lock (syncObj)         {             StreamWriter sw = new StreamWriter("forward.txt");             IEnumerator<Item> enumerator = items.GetEnumerator();             while (true)                {                }             while (true)             {                 if (enumerator.MoveNext())                 {                     Item current = enumerator.Current;                    string message = current.ItemId + " Product Mask: "                         + ((int)current.Products).ToString();                     sw.WriteLine(message);                 }                 else                 {                     break;                 }             }             sw.Close();         }     } } 

Review the code—I hope that the problem is obvious. The lock statement is a shortcut to calling the Monitor.Enter method. After acquiring the locks, the program enters an infinite loop, which was shown previously. Because execution never continues past the loop where the locks are released, the locks are still being held. Remove the extraneous while(true) loop and retry the program. Before recompiling the application, you have to kill the hung process. The forward.txt file should be created and contain transactions.

Threads Walkthrough 2

The Store application appears to be working, but not in all circumstances. Delete the forward.txt and reverse.txt files. End any current sessions of the Store application. Start a new session of the Store application and add a couple of transactions.

1. Click the Reverse Enumerate button followed by the Enumerate button. Close the application and check for the forward.txt and reverse.txt files. Neither file is created. Why not?

2. Restart the Store application. Add two new transactions. Click the Reverse Enumerate button followed by the Enumerate button.

3. Start WinDbg and attach to the Store application.

4. List the available threads with the !threads command. Threads 4 and 5 have a positive lock count. Both threads are waiting for something:

    0:006> !threads ThreadCount: 4 UnstartedThread: 0 BackgroundThread: 1 PendingThread: 0 DeadThread: 0 Hosted Runtime: no                                       PreEmptive    GC Alloc          Lock        ID OSID ThreadOBJ     State    GC        Context       Domain   Count    0    1  e54 001501f8       6020 Enabled  013e7afc:013e7b68 001483a8     0    2    2  d84 00153e40       b220 Enabled  00000000:00000000 001483a8     0    4    3  2e0 00191f60    200b020 Enabled  013d9bec:013dbb68 001483a8     1    5    4  ccc 00190b98    200b020 Enabled  013dfb9c:013e1b68 001483a8     1 

   The !syncblk command reports the syncblock entries. Thread 5 is using an Item instance as a monitor. Thread 4 is using an Object instance as a monitor. This confirms Threads 4 and 5 as the potential source of the problem. The other threads are not using monitors:

    0:006> !syncblk Index SyncBlock MonitorHeld Recursion Owning Thread Info  SyncBlock Owner     2 00174854            3         1 00190b98   ccc   5   01392440 System.Collections.Generic.List`1[[Store.Item, Store]]    21 001747f4            3         1 00191f60   2e0   4   01392468 System.Object ----------------------------- Total           44 CCW             0 RCW             0 ComClassFactory 0 Free            0 

5. Perform a stack trace on Threads 4 and 5. Notice the inclusion of the AwareLock::Enter method, which is a marker of thread synchronization. Also note that the top of the call stack is populated with WaitForMultipleObjects methods, which means the thread is currently blocked on something:

    0:004> kb ChildEBP RetAddr  Args to Child 0358f4a0 7c90e9ab 7c8094f2 00000001 0358f4cc ntdll!KiFastSystemCallRet 0358f4a4 7c8094f2 00000001 0358f4cc 00000001 ntdll!ZwWaitForMultipleObjects+0xc 0358f540 79f4aa60 00000001 00174868 00000000 KERNEL32!WaitForMultipleObjectsEx+0x12c 0358f5a8 79f16d92 00000001 00174868 00000000 mscorwks!WaitForMultipleObjectsEx_SO_TOLE RANT+0x6f 0358f5c8 79f16d03 00000001 00174868 00000000 mscorwks!Thread::DoAppropriateAptStateWai t+0x3c 0358f64c 79f16b9e 00000001 00174868 00000000 mscorwks!Thread::DoAppropriateWaitWorker+ 0x144 0358f69c 79f4a9d9 00000001 00174868 00000000 mscorwks!Thread::DoAppropriateWait+0x40 0358f6f8 79ebc06e ffffffff 00000001 00000000 mscorwks!CLREvent::WaitEx+0xf7 0358f708 7a0fd093 ffffffff 00000001 00000000 mscorwks!CLREvent::Wait+0x17 0358f794 7a0fd28f 00191f60 ffffffff 00191f60 mscorwks!AwareLock::EnterEpilog+0x94 0358f7b0 79f0fe6a 8a20e59b 0358f888 01392214 mscorwks!AwareLock::Enter+0x61 

6. Look at the parameters for WaitForMultiple objects. Thread 4 is waiting for a single synchronization object, which is the first parameter. The second parameter is an address, which is a pointer to an array of handles. Dump that parameter to find the handle to the synchronization object:

    0:004> dd 00174868 00174868  00000658 0000000d 00000000 00000000 00174878  00000000 00000000 00000000 00000000 00174888  00000000 00000000 00000000 80000023 

7. The handle to the synchronization object is 0x00000658. Use the !handle command to obtain more information on that handle. It is an event handle:

    0:004> !handle 00000658 Handle 658   Type         Event 

8. Repeat steps 1 through 7 for Thread 5. The result should be similar.

   The problem has been isolated to Threads 4 and 5. Threads 4 and 5 are started in the Forward and Reverse handlers. Here is the source code for these methods. Both methods have nested locks. However, the locks in the Forward and Reverse methods are in reverse order, which is causing a deadlock.

    private void Forward() {     lock (items)     {         lock (syncObj)         {             StreamWriter sw = new StreamWriter("forward.txt");             IEnumerator<Item> enumerator = items.GetEnumerator();             while (true)             {                 // other code             }             sw.Close();         }     } } Object syncObj= new Object(); private void Reverse() {     lock (syncObj)     {         Thread.Sleep(5000);         lock (items)         {             StreamWriter sw = new StreamWriter("reverse.txt");             items.Reverse();             IEnumerator<Item> enumerator = items.GetEnumerator();             while (true)             {                // other code             }             items.Reverse();             sw.Close();         }     } 

9. Reverse the order of the locks in either method, which resolves the problem. Restart the Store application and test.