Mark S. Rasmussen improve.dk
Oct 08
2013

One of the main culprits when it comes to ASP.NET concurrency is caused by the fact that default sesion state has been implemented using a pessimistic locking pattern. Basically, any standard handler, whether that be an ASPX page, a generic handler or an ASMX web service, goes through the following steps:

  • Retrieve & exclusively lock session
  • Execute request handler
  • Save & unlock updated session (whether updates have been made or not)

What this means is that, for a given session, only one request can execute concurrently. Any other requests, from that same session, will block, waiting for the session to be released. For the remainder of this post I’ll concentrate on generic HttpHandlers, but this problem & solution is common to for ASPX and ASMX pages as well.

Disabling Session State

If your handler doesn’t require session state, all you have to do is to not implement the IRequiresSessionState interface, given that HttpHandlers by default do not have access to session state:

public class MyHandler : IHttpHandler
{
	public void ProcessRequest(HttpContext context)
	{
		// Perform some task
	}
	
	public bool IsReusable { get { return false; } }
}

By not enabling session state, no session will be locked and you can execute as many concurrent requsts as your server can handle.

Enabling Session State

If you do need session state, simply implement the IRequiresSessionState interface, like so:

public class MyHandler : IHttpHandler, IRequiresSessionState
{
	public void ProcessRequest(HttpContext context)
	{
		// Perform some task
	}
	
	public bool IsReusable { get { return false; } }
}

The IRequiresSessionState interface carries no functionality at all, it’s simply a marker interface that tells the ASP.NET request pipeline to acquire session state for the given request. By implementing this interface you now have read+write access to the current session.

Read-Only Session State

If all you need is to read session state, while not having to be able to write it, you should implement the IReadOnlySessionState interface instead, like so:

public class MyHandler : IHttpHandler, IReadOnlySessionState
{
	public void ProcessRequest(HttpContext context)
	{
		// Perform some task
	}
	
	public bool IsReusable { get { return false; } }
}

Implementing this interface changes the steps performed by the page slightly:

  • Retrieve session, without locking
  • Execute request handler
  • Save & unlock updated session (whether updates have been made or not)

While session is still read as usual, it’s just not persisted back after the request is done. This means you can actually update the session, without causing any exceptions. However, as the session is never persisted, your changes won’t be saved after the request is done. For read-only use this also saves the superfluous save operation which can be costly if you’re using out-of-process session state like State or SQL Server.

Switching Between Read+Write and Read-Only Session State Programmatically

While this is great, we sometimes need something in between. Consider the following scenario:<7p>

  • You’ve got a single handler that’s heavily requested.
  • On the first request you need to perform some expensive lookup to load some data that will be used in all further requests, but is session specific, and will thus be stored in session state.
  • If you implement IRequiresSessionState, you can easily detect the first request (Session[“MyData”] == null), load the data, store it in session and then reuse it in all subsequent requests. However, this ensures only one request may execute at a time, due to the session being exclusively locked while the handler executes.
  • If you instead implement IReadOnlySessionState, you can execute as many handlers concurrently as you please, but you’ll have to do that expensive data loading on each request, seeing as you can’t store it in session.

Imagine if you could dynamically decide whether to implement the full read+write enabled IRequiresSessionState or just the read enabled IReadOnlySession state. That way you could implement IRequiresSessionState for the first request and just implement IReadOnlySessionState for all of the subsequent requests, once a session has been established.

And guess what, from .NET 4.0 onwards, that’s possible!

Enter HttpContext.SetSessionStateBehavior

Looking at the ASP.NET request pipeline, session state is loaded in the “Acquire state” event. At any point, before this event, we can set the session behavior programmatically by calling HttpContext.SetSessionStateBehavior. Setting the session programmatically through HttpContext.SetSessionStateBehavior will override any interfaces implemented by the handler itself.

Here’s a full example of an HttpModule that runs on each request. In the PostMapRequestHandler event (which fires just before the AcquireState event), we inspect the HttpHandler assigned to the request. If it implements the IPreferReadOnlySessionState interface (a custom marker interface), the SessionStateBehavior is set to ReadOnly, provided there already is an active session (which the presence of an ASP.NET_SessionId cookie indicates). If there is no session cookie present, or if the handler doesn’t implement IPreferReadOnlySessionState, then it’s left up to the handler default - that is, the implemented interface, to decide.

public class RequestHandler : IHttpModule
{
	public void Init(HttpApplication context)
	{
		context.PostMapRequestHandler += context_PostMapRequestHandler;
	}
	
	void context_PostMapRequestHandler(object sender, EventArgs e)
	{
		var context = HttpContext.Current;
		
		if (context.Handler is IPreferReadOnlySessionState)
		{
			if (context.Request.Headers["Cookie"] != null && context.Request.Headers["Cookie"].Contains("ASP.NET_SessionId="))
				context.SetSessionStateBehavior(SessionStateBehavior.ReadOnly);
		}
	}
}

Now all we need to do is to also implement the IPreferReadOnlySessionState interface in the handlers that can do with read-only sesion state, provided a session is already present:

public interface IPreferReadOnlySessionState
{ }
public class MyHandler : IHttpHandler, IRequiresSessionState, IPreferReadOnlySessionState
{
	public void ProcessRequest(HttpContext context)
	{
		// Perform some task
	}
	
	public bool IsReusable { get { return false; } }
}

And just like that, the first request has read+write access to the session state, while all subsequent requests only have read access, greatly increasing the concurrency of the handler.

Sep 23
2013

Mailgun has a very neat feature that enables you to basically convert incoming emails to a POST request to a URL of your choice, also known as a webhook. Using this, you can easily have your application respond to email events. However, as this URL/service needs to be publically available, verifying Mailgun webhooks is very important, ensuring requests actually come from Mailgun, and not someone impersonating Mailgun.

The code required for verifying Mailgun forwards is very simple and doesn’t require much explanation:

/// <summary>
/// Verifies that the signature matches the timestamp & token.
/// </summary>
/// <returns>True if the signature is valid, otherwise false.</returns>
public static bool VerifySignature(string key, int timestamp, string token, string signature)
{
	var encoding = Encoding.ASCII;
	var hmacSha256 = new HMACSHA256(encoding.GetBytes(key));
	var cleartext = encoding.GetBytes(timestamp + token);
	var hash = hmacSha256.ComputeHash(cleartext);
	var computedSignature = BitConverter.ToString(hash).Replace("-", "").ToLower();

	return computedSignature == signature;
}

Use sample:

// All these values are provided by the Mailgun request
var key = "key-x3ifab7xngqxep7923iuab251q5vhox0";
var timestamp = 1568491354;
var token = "asdoij2893dm98m2x0a9sdkf09k423cdm";
var signature = "AF038C73E912A830FFC830239ABFF";

// Verify if request is valid
bool isValid = VerifySignature(key, timestamp, token, signature);

As the manual says you simply need to calculate a SHA256 HMAC of the concatenated timestamp and token values, after which you can verify that it matches the Mailgun provided signature. The key is the private API key, retrievable from the Mailgun control panel.

Jun 04
2013

Unfortunately, once in a while, computers fail. If you’re running Windows you’ve probably witnessed the dreaded Blue Screen of Death, commonly referred to as a BSOD. Once the BSOD occurs, some machines will immediately restart, before you’ve got a chance to actually see what happened. Other times users will just report that the BSOD happened, without noting anything down about what the message actually said. In this post I’ll show you how analyzing BSOD minidump files using Windbg will enable you to find the cause of the BSOD after the fact.

Enabling Dump Files

By default, never Windows installs will automatically create minidump files once a BSOD occurs. Once restarted, you should be able to see a .dmp file here:

C:\Windows\Minidump

If you don’t see any .dmp files there, or if the directory doesn’t exist, you may have to tell Windows to create minidump files when the BSOD occurs. To do so, press the Win+Break keys to open up the System control panel. Now click Advanced system settings in the left menu. Once there, go to the Advanced tab and click the Settings… button under the Startup and Recovery section. Now make sure the Write debugging information setting is set to anything but “none”:

Analyzing BSOD Minidump Files Using Windbg

Once a dump file has been created, you can analyze it using Windbg. Start by opening Windbg and pressing the Ctrl+D keys. Now select the .dmp file you want to analyze and click Open. This should yield something like this:

Microsoft (R) Windows Debugger Version 6.12.0002.633 AMD64
Copyright (c) Microsoft Corporation. All rights reserved.


Loading Dump File [C:\Windows\Minidump\040813-15974-01.dmp]
Mini Kernel Dump File: Only registers and stack trace are available

Symbol search path is: symsrv*symsrv.dll*c:\symbols*http://msdl.microsoft.com/download/symbols
Executable search path is: 
Windows 7 Kernel Version 7601 (Service Pack 1) MP (12 procs) Free x64
Product: WinNt, suite: TerminalServer SingleUserTS
Built by: 7601.18044.amd64fre.win7sp1_gdr.130104-1431
Machine Name:
Kernel base = 0xfffff800`0300c000 PsLoadedModuleList = 0xfffff800`03250670
Debug session time: Mon Apr  8 22:17:47.016 2013 (UTC + 2:00)
System Uptime: 0 days 1:36:19.860
Loading Kernel Symbols
...............................................................
................................................................
........................
Loading User Symbols
Loading unloaded module list
...............
*******************************************************************************
*                                                                             *
*                        Bugcheck Analysis                                    *
*                                                                             *
*******************************************************************************

Use !analyze -v to get detailed debugging information.

BugCheck FE, {4, fffffa803c3c89e0, fffffa803102e230, fffffa803e765010}

Probably caused by : FiioE17.sys ( FiioE17+1d21 )

Followup: MachineOwner

Already this tells us a couple of things - your OS details, when exactly the problem occurred as well as what module probably caused the issue (FiioE17.sys in this case). Also, it tells you how to proceed:

Use !analyze -v to get detailed debugging information.

As suggested, let’s try and run the !analyze -v command:

11: kd> !analyze -v
*******************************************************************************
*                                                                             *
*                        Bugcheck Analysis                                    *
*                                                                             *
*******************************************************************************

BUGCODE_USB_DRIVER (fe)
USB Driver bugcheck, first parameter is USB bugcheck code.
Arguments:
Arg1: 0000000000000004, IRP_URB_DOUBLE_SUBMIT The caller has submitted an irp
	that is already pending in the USB bus driver.
Arg2: fffffa803c3c89e0, Address of IRP
Arg3: fffffa803102e230, Address of URB
Arg4: fffffa803e765010

Debugging Details:
------------------

CUSTOMER_CRASH_COUNT:  1

DEFAULT_BUCKET_ID:  VISTA_DRIVER_FAULT

BUGCHECK_STR:  0xFE

PROCESS_NAME:  audiodg.exe

CURRENT_IRQL:  2

LAST_CONTROL_TRANSFER:  from fffff88008326f4b to fffff80003081c40

STACK_TEXT:  
fffff880`0e482fd8 fffff880`08326f4b : 00000000`000000fe 00000000`00000004 fffffa80`3c3c89e0 fffffa80`3102e230 : nt!KeBugCheckEx
fffff880`0e482fe0 fffff880`0833244a : fffffa80`3ae97002 fffffa80`3b8caad0 00000000`00000000 fffffa80`3ae97050 : USBPORT!USBPORT_Core_DetectActiveUrb+0x127
fffff880`0e483030 fffff880`0833ae74 : fffffa80`3c3c89e0 fffffa80`3af7000a fffffa80`3c3c89e0 fffffa80`3102e230 : USBPORT!USBPORT_ProcessURB+0xad6
fffff880`0e4830e0 fffff880`08314af4 : 00000000`00000000 fffffa80`3af7b050 fffffa80`3e5d1720 fffffa80`3c3c89e0 : USBPORT!USBPORT_PdoInternalDeviceControlIrp+0x138
fffff880`0e483120 fffff880`00fa97a7 : fffffa80`3c3c89e0 fffffa80`31192040 fffffa80`3c3c89e0 fffffa80`3c3c89e0 : USBPORT!USBPORT_Dispatch+0x1dc
fffff880`0e483160 fffff880`00fb1789 : fffff880`00fcfb50 fffffa80`3d944ed1 fffffa80`3c3c8d38 fffffa80`3c3c8d38 : ACPI!ACPIDispatchForwardIrp+0x37
fffff880`0e483190 fffff880`00fa9a3f : fffff880`00fcfb50 fffffa80`316a7a90 fffffa80`3c3c89e0 fffffa80`3ab6c050 : ACPI!ACPIIrpDispatchDeviceControl+0x75
fffff880`0e4831c0 fffff880`088ca566 : 00000000`00000000 00000000`00000004 fffffa80`3ab6c050 fffffa80`3c2bd440 : ACPI!ACPIDispatchIrp+0x12b
fffff880`0e483240 fffff880`088fad8f : 00000000`00000000 00000000`00000000 fffffa80`3c2bd440 00000000`00000000 : usbhub!UsbhFdoUrbPdoFilter+0xde
fffff880`0e483270 fffff880`088c8fb7 : fffffa80`3c3c89e0 fffffa80`3a976ce0 fffffa80`3c3c89e0 fffffa80`3c3c89e0 : usbhub!UsbhPdoInternalDeviceControl+0x373
fffff880`0e4832c0 fffff880`00fa97a7 : fffffa80`3c3c89e0 fffff800`031b630d fffffa80`3b7be100 00000000`00000801 : usbhub!UsbhGenDispatch+0x57
fffff880`0e4832f0 fffff880`00fb1789 : fffff880`00fcfb50 00000000`00000001 fffffa80`3c393b58 fffffa80`3c3c8d38 : ACPI!ACPIDispatchForwardIrp+0x37
fffff880`0e483320 fffff880`00fa9a3f : fffff880`00fcfb50 fffffa80`316a8a90 fffffa80`3c3c89e0 fffffa80`3c393b58 : ACPI!ACPIIrpDispatchDeviceControl+0x75
fffff880`0e483350 fffff880`08c9bec4 : 00000000`00000000 fffffa80`3c326938 fffffa80`3c393b58 00000000`00000000 : ACPI!ACPIDispatchIrp+0x12b
fffff880`0e4833d0 fffff880`08c98812 : fffffa80`3c393b58 fffffa80`3c3c89e0 fffffa80`00000324 fffffa80`3c3c89e0 : usbccgp!UsbcForwardIrp+0x30
fffff880`0e483400 fffff880`08c98aba : fffffa80`3c326838 00000000`00220003 fffffa80`3c3c89e0 fffffa80`3c393b58 : usbccgp!DispatchPdoUrb+0xfa
fffff880`0e483440 fffff880`08c9672e : 00000000`0000000f fffffa80`3c393b50 fffffa80`3c393b58 fffffa80`3c3c89e0 : usbccgp!DispatchPdoInternalDeviceControl+0x17a
fffff880`0e483470 fffff880`08cb3d21 : fffffa80`3c393a00 fffffa80`3c3c8901 fffffa80`3c3c8900 00000000`00000000 : usbccgp!USBC_Dispatch+0x2de
fffff880`0e4834f0 fffffa80`3c393a00 : fffffa80`3c3c8901 fffffa80`3c3c8900 00000000`00000000 fffffa80`3c373010 : FiioE17+0x1d21
fffff880`0e4834f8 fffffa80`3c3c8901 : fffffa80`3c3c8900 00000000`00000000 fffffa80`3c373010 00000000`00000000 : 0xfffffa80`3c393a00
fffff880`0e483500 fffffa80`3c3c8900 : 00000000`00000000 fffffa80`3c373010 00000000`00000000 fffffa80`3c3b7f30 : 0xfffffa80`3c3c8901
fffff880`0e483508 00000000`00000000 : fffffa80`3c373010 00000000`00000000 fffffa80`3c3b7f30 fffff880`08cb47fd : 0xfffffa80`3c3c8900


STACK_COMMAND:  kb

FOLLOWUP_IP: 
FiioE17+1d21
fffff880`08cb3d21 ??              ???

SYMBOL_STACK_INDEX:  12

SYMBOL_NAME:  FiioE17+1d21

FOLLOWUP_NAME:  MachineOwner

MODULE_NAME: FiioE17

IMAGE_NAME:  FiioE17.sys

DEBUG_FLR_IMAGE_TIMESTAMP:  50b30686

FAILURE_BUCKET_ID:  X64_0xFE_FiioE17+1d21

BUCKET_ID:  X64_0xFE_FiioE17+1d21

Followup: MachineOwner

This tells us a number of interesting things:

  • The BSOD error was: BUGCODE_USB_DRIVER
  • This is the error caused by the driver: IRP_URB_DOUBLE_SUBMIT The caller has submitted an irp that is already pending in the USB bus driver.
  • The process that invoked the error: audiodg.exe
  • The stack trace of the active thread on which the error occurred. Note that Windbg can’t find the right symbols as this is a proprietary driver with no public symbols. Even so, to the developer of said driver, the above details will help immensely.
  • The driver name: FiioE17.sys

With the above options, you’ve got a lot of details that can be sent to the developer, hopefully enabling him/her/them to fix the issue. For now, I’ll have to unplug my Fiio E17 USB DAC :(

May 28
2013

I’m delighted to announce that I’ll be speaking at this years SQL PASS Summit in Charlotte, North Carolina. Having submitted several times before, unsuccessfully, I’m really happy to have made the cut this year. Looking at the lineup of speakers, I take great pride in being given the opportunity.

My Sessions

That’s right, not just one session, but two! And as if that wasn’t enough, the two selected sessions are my absolute favorite ones to perform! I’ve presented both several times before and thanks to great feedback from the audiences I’ve slowly fine tuned the format and content.

Top Tricks and Best Practices for .NET SQL Server Developers

This is a session chock-full of easy-to-use tips, tricks and gotchas that can be implemented immediately. If you’re either a .NET developer yourself, or if you have .NET developers on your team, using SQL Server, this session is sure to be an eye opener with valuable lessons.

Being the acting DBA while doing development and managing a team of .NET developers, I’ve learned a trick or two through the years. For this session, I’ve gathered my list of top tricks any .NET developer should know and use when dealing with SQL Server. We’ll cover how to use TransactionScopes without locking up the database, avoiding MSDTC escalation, using internal batching functions in the BCL through reflection, avoiding unnecessary round trips, and much more. These are tips, tricks, and best practices that I ensure all my developers are taught before they have a chance of committing code to our production systems.

Understanding Data Files at the Byte Level

The best part about this session, for me, is watching heads explode only 15 minutes in when I make a live demonstration of how to reverse engineer SQL Server, to persuade it into describing its own data file format. In just 75 minutes I will give you not only a thorough tour of the MDF file format, but also a plethora of techniques on how to analyze your own databases internal storage as well. Using these techniques you’ll be well armed when it comes to schema discussions, column type choice and for those rare events where you need to dive just a bit below the surface to discover what’s really happening.

This session won’t explain when to use a heap instead of an index, but you will learn how they work – and differ – behind the scenes. Demonstrations will show how data files are organized on the disk and how that organization allows SQL Server to effectively query the data. Knowing how data files are organized will in turn help immensely when it comes to optimizing databases for both performance and storage efficiency.

May 23
2013

Recently I’ve begun using New Relic, and so far it’s been an excellent experience. About two weeks ago I started using their .NET Agent API to customize some of the data reported by our application to their servers. This makes the data way more valuable to us as we can now selectively ignore certain parts of our application while getting better reporting from other, more critical, parts of the application.

Random Outages

Unfortunately, in the last couple of weeks, ever since introducing the .NET Agent API, we’ve had a number of outages (thankfully invisible to the customers due to a self-healing load-balancer setup shielding the individual application servers) where one of our applications servers would randomly start throwing the same exception on all requests:

System.TypeLoadException: Could not load type 'NewRelic.Agent.Core.AgentApi' from assembly 'NewRelic.Api.Agent, Version=2.5.112.0, Culture=neutral, PublicKeyToken=06552fced0b33d87'. 
at NewRelic.Api.Agent.NewRelic.SetTransactionName(String category, String name) 
at System.Web.HttpApplication.SyncEventExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute() 
at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously)

The error seemed to crop up randomly on all of our servers, though not at the same time and in with no predictable patterns - except it was always just after an application pool recycle. Once the error occurred it would continue happening until we either recycled the pool manually or it was recycled automatically according to its schedule.

The Support Experience

To make a long story short, I opened a support case with New Relic as I couldn’t find anything in neither their docs, nor on Google, related to the specific exception. After about a week of going back and forth between their engineers and me they managed to track down the root cause:

It appears that some of the caching we do is not being correctly invalidated. I have removed the caching code and you should see this fix in our next release.

In the meantime I’ve had to stop using the .NET Agent API to avoid the issue from happening again. This doesn’t mean we won’t get any data; it’s just not as well polished as before. I’m eagerly looking forward to the next agent release so we can get back to using the .NET Agent API again.

In conclusion I must say I’m impressed by the overall support experience. The responses have been quick and professional. Naturally I’d prefer not to have had any issues, but we all know they can happen, and in those cases it’s a matter of having a solid triage process - and in this case I’m just happy to be able to assist in identifying the cause.

May 21
2013

At our office, all machines are using a local Windows DNS server for their outgoing DNS queries. This allows us to make internal zones like .ipaperlan that points to all of our internal systems, while setting up the DNS server to forward all unknown queries to Google DNS. One feature I’m missing in the standard Windows DNS server is the option to partially forward individual zones. However, there is a workaround that will allow you to setup partial DNS forwarding using individual Windows DNS zones.

The Scenario

Imagine you have a domain improve.dk that already has a number of public DNS records like the following.

In this case all I want to do is to add a record on our internal network, jira.improve.dk. As this record should only be made available internally, we can’t just add it to the public DNS records for the domain.

I could make a new DNS zone for the improve.dk domain in our local DNS server, but that would result in all DNS queries for improve.dk being answered by our local DNS server, rather than being forwarded. As long as I recreate all public DNS records in our local DNS server, this would work fine, but it’s not a viable solution as I’d now have to keep the two DNS setups in sync manually.

The Solution

Instead of creating a zone for the whole improve.dk domain, you can make a zone specifically for just the record you need to add. First right click “Forward Lookup Zones” and select “New Zone…” and then follow these steps (pretty much all defaults):

Now that the zone has been created, simply right click it and choose “New Host (A or AAAA)…”. In the dialog, leave the Name blank as that’ll affect the record itself, while entering the desired IP like so:

And just like that, DNS lookups for jira.improve.dk will now be answered locally while all other requests will be forwarded to whatever DNS server is set up as the forwarding server.

One word of warning - You might not want to do this on Active Directory domain servers as they’re somewhat more finicky about their DNS setup. I’m honestly not aware of what complications might arise, so I’d advice you to be careful or perhaps find another solution.

May 13
2013

Thanks to Justin Dearing (b|t), OrcaMDF is now available on NuGet!

OrcaMDF being on NuGet means the bar just got lowered even more if you want to try it out. Let me show you how easy it is to read the Adventureworks 2008 R2 Database using OrcaMDF:

To begin, let’s create a vanilla .NET Console Application:

Once the solution has been made, right click References and go to Manage NuGet Packages:

Once the dialog opens, simply search for OrcaMDF and click the Install button for the OrcaMDF.Core package:

When done, you should now see a small green checkmark next to the OrcaMDF.Core package:

At this point the OrcaMDF.Core assembly will be available and all you have to do is start using it. For example you could print out all of the products along with their prices by modifying the Program.cs file like so (you’ll have to alter the path to AdventureWorks2008R2_Data.mdf file so it points to a local copy (which must not be in use by SQL Server) on your machine):

using System;
using OrcaMDF.Core.Engine;

namespace ConsoleApplication1
{
	class Program
	{
		static void Main()
		{
			using (var db = new Database(@"C:\AdventureWorks2008R2_Data.mdf"))
			{
				var scanner = new DataScanner(db);

				foreach (var row in scanner.ScanTable("Product"))
				{
					Console.WriteLine(row.Field<string>("Name"));
					Console.WriteLine("Price: " + row.Field<double>("ListPrice"));
					Console.WriteLine();
				}
			}
		}
	}
}

And then just running the solution:

And there you have it, in just a few quick short steps you’ve now fetched OrcaMDF and read the Products table, from the standard AdventureWorks 2008 R2 database, without even touching SQL Server.

With OrcaMDF now being available on NuGet as well as with a simple GUI, it really doesn’t get any simpler to take it for a spin :)

May 07
2013

When your w3wp process is stuck at 100% like, like when I used a non-thread-safe Dictionary concurrently, you may want to identify what request the runaway thread is actually serving. Let me show you how to identify which request caused a runaway thread, using windbg.

First you’ll want to identify the process ID (PID) of the w3wp process. In my case, that’s 102600:

Next you’ll want to start up Windbg (make sure to use the correct bitness (x86 vs x64) that corresponds to the bitness of your process). Once started, press F6 to open up the Attach to Process dialog. Once open, enter your process ID and click OK.

Doing so should bring up the Command window, ready for your command:

As the first thing, start out by loading the Son of Strike extension, allowing us to debug managed code.

0:039> .loadby sos clr

Then continue by running the !runaway command to get a list of runaway (basically threads using lots of CPU) threads:

0:039> !runaway

 User Mode Time
  Thread       Time
  20:14930      0 days 0:21:44.261
  21:15204      0 days 0:21:00.878
  27:19d48      0 days 0:04:23.860
  32:18748      0 days 0:02:59.260
  31:18bcc      0 days 0:02:19.277
  30:19d80      0 days 0:01:44.083
  25:19ec0      0 days 0:01:32.446
  24:16534      0 days 0:01:31.135
  29:19a80      0 days 0:01:08.297
  23:19110      0 days 0:00:30.591
   6:19b40      0 days 0:00:00.109
  26:18a14      0 days 0:00:00.015
   0:19dcc      0 days 0:00:00.015
  39:16fa8      0 days 0:00:00.000
  ...

Threads 20 & 21 seem to be the interesting ones. Let’s start out by selecting thread #20 as the active thread:

0:039> ~20s

000007fe`913a15d9 3bc5            cmp     eax,ebp

Once selected, we can analyze the stack and its parameters by running the !CLRStack command with the -p parameter:

0:020> !CLRStack -p

OS Thread Id: 0x14930 (20)
        Child SP               IP Call Site
000000000dccdb00 000007fe913a15d9 System.Collections.Generic.Dictionary`2[[System.Int16, mscorlib],[System.__Canon, mscorlib]].FindEntry(Int16)
    PARAMETERS:
        this = <no data>
        key = <no data>

000000000dccdb50 000007fe913a14c0 System.Collections.Generic.Dictionary`2[[System.Int16, mscorlib],[System.__Canon, mscorlib]].get_Item(Int16)
    PARAMETERS:
        this = <no data>
        key = <no data>

000000000dccdb80 000007fe91421cbb iPaper.BL.Backend.Modules.Languages.LanguageCache.GetLanguageByID(Int32, iPaper.BL.Backend.Infrastructure.PartnerConfiguration.IPartnerConfig) [e:\iPaperCMS\BL\Backend\Modules\Languages\LanguageCache.cs @ 44]
    PARAMETERS:
        languageID (0x000000000dccdc20) = 0x0000000000000001
        partnerConfig (0x000000000dccdc28) = 0x00000000fffc3e50

000000000dccdc20 000007fe91421dfa iPaper.BL.Backend.Modules.Languages.Language.GetFontFileForLanguage(Int32, iPaper.BL.Backend.Infrastructure.PartnerConfiguration.IPartnerConfig) [e:\iPaperCMS\BL\Backend\Modules\Languages\Language.cs @ 37]
    PARAMETERS:
        languageID (0x000000000dccdc70) = 0x0000000000000001
        partnerConfig (0x000000000dccdc78) = 0x00000000fffc3e50

000000000dccdc70 000007fe91417400 iPaper.Web.FlexFrontend.BL.Common.CachedUrlInformation.GetFromUrlDirectoryPath(System.String, System.String, iPaper.BL.Backend.Infrastructure.PartnerConfiguration.IPartnerConfig) [e:\iPaperCMS\Frontend\BL\Common\CachedUrlInformation.cs @ 89]
    PARAMETERS:
        url (0x000000000dccde80) = 0x00000003fff27e30
        host (0x000000000dccde88) = 0x00000003fff29618
        partnerConfig (0x000000000dccde90) = 0x00000000fffc3e50

000000000dccde80 000007fe91417576 iPaper.Web.FlexFrontend.BL.Common.CachedUrlInformation.GetFromHttpContext(System.String, System.Web.HttpContext, iPaper.BL.Backend.Infrastructure.PartnerConfiguration.IPartnerConfig) [e:\iPaperCMS\Frontend\BL\Common\CachedUrlInformation.cs @ 122]
    PARAMETERS:
        paperPath (0x000000000dcce010) = 0x00000003fff27e30
        context (0x000000000dcce018) = 0x00000000fffa6040
        partnerConfig (0x000000000dcce020) = 0x00000000fffc3e50

000000000dcce010 000007fe91415529 iPaper.Web.FlexFrontend.BL.RequestHandler.RequestHandler.loadFrontendContext(System.String) [e:\iPaperCMS\Frontend\BL\RequestHandler\RequestHandler.cs @ 469]
    PARAMETERS:
        this (0x000000000dcce260) = 0x00000000fffa9590
        paperPath (0x000000000dcce268) = 0x00000003fff27e30

000000000dcce260 000007fe91414b73 iPaper.Web.FlexFrontend.BL.RequestHandler.RequestHandler.context_PostAcquireRequestState(System.Object, System.EventArgs) [e:\iPaperCMS\Frontend\BL\RequestHandler\RequestHandler.cs @ 95]
    PARAMETERS:
        this (0x000000000dcce5f0) = 0x00000000fffa9590
        sender (0x000000000dcce5f8) = 0x00000000fffa8a50
        e (0x000000000dcce600) = 0x00000000fffaebb0

000000000dcce5f0 000007fedb72c520 System.Web.HttpApplication+SyncEventExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()
    PARAMETERS:
        this = <no data>

000000000dcce650 000007fedb70b745 System.Web.HttpApplication.ExecuteStep(IExecutionStep, Boolean ByRef)
    PARAMETERS:
        this (0x000000000dcce6f0) = 0x00000000fffa8a50
        step (0x000000000dcce6f8) = 0x00000000fffabc28
        completedSynchronously (0x000000000dcce700) = 0x000000000dcce77a

000000000dcce6f0 000007fedb72a4e1 System.Web.HttpApplication+PipelineStepManager.ResumeSteps(System.Exception)
    PARAMETERS:
        this (0x000000000dcce7d0) = 0x00000000fffac718
        error = <no data>

000000000dcce7d0 000007fedb70b960 System.Web.HttpApplication.BeginProcessRequestNotification(System.Web.HttpContext, System.AsyncCallback)
    PARAMETERS:
        this = <no data>
        context = <no data>
        cb = <no data>

000000000dcce820 000007fedb704c8e System.Web.HttpRuntime.ProcessRequestNotificationPrivate(System.Web.Hosting.IIS7WorkerRequest, System.Web.HttpContext)
    PARAMETERS:
        this (0x000000000dcce8c0) = 0x00000000fff3fb20
        wr (0x000000000dcce8c8) = 0x00000000fffa5eb0
        context (0x000000000dcce8d0) = 0x00000000fffa6040

000000000dcce8c0 000007fedb70e771 System.Web.Hosting.PipelineRuntime.ProcessRequestNotificationHelper(IntPtr, IntPtr, IntPtr, Int32)
    PARAMETERS:
        rootedObjectsPointer = <no data>
        nativeRequestContext (0x000000000dccea58) = 0x0000000000ccccc0
        moduleData = <no data>
        flags = <no data>

000000000dccea50 000007fedb70e2c2 System.Web.Hosting.PipelineRuntime.ProcessRequestNotification(IntPtr, IntPtr, IntPtr, Int32)
    PARAMETERS:
        rootedObjectsPointer = <no data>
        nativeRequestContext = <no data>
        moduleData = <no data>
        flags = <no data>

000000000dcceaa0 000007fedbe6b461 DomainNeutralILStubClass.IL_STUB_ReversePInvoke(Int64, Int64, Int64, Int32)
    PARAMETERS:
        <no data>
        <no data>
        <no data>
        <no data>

000000000dccf298 000007fef0a9334e [InlinedCallFrame: 000000000dccf298] System.Web.Hosting.UnsafeIISMethods.MgdIndicateCompletion(IntPtr, System.Web.RequestNotificationStatus ByRef)
000000000dccf298 000007fedb7b9c4b [InlinedCallFrame: 000000000dccf298] System.Web.Hosting.UnsafeIISMethods.MgdIndicateCompletion(IntPtr, System.Web.RequestNotificationStatus ByRef)
000000000dccf270 000007fedb7b9c4b DomainNeutralILStubClass.IL_STUB_PInvoke(IntPtr, System.Web.RequestNotificationStatus ByRef)
    PARAMETERS:
        <no data>
        <no data>

000000000dccf340 000007fedb70e923 System.Web.Hosting.PipelineRuntime.ProcessRequestNotificationHelper(IntPtr, IntPtr, IntPtr, Int32)
    PARAMETERS:
        rootedObjectsPointer = <no data>
        nativeRequestContext = <no data>
        moduleData = <no data>
        flags = <no data>

000000000dccf4d0 000007fedb70e2c2 System.Web.Hosting.PipelineRuntime.ProcessRequestNotification(IntPtr, IntPtr, IntPtr, Int32)
    PARAMETERS:
        rootedObjectsPointer = <no data>
        nativeRequestContext = <no data>
        moduleData = <no data>
        flags = <no data>

000000000dccf520 000007fedbe6b461 DomainNeutralILStubClass.IL_STUB_ReversePInvoke(Int64, Int64, Int64, Int32)
    PARAMETERS:
        <no data>
        <no data>
        <no data>
        <no data>

000000000dccf768 000007fef0a935a3 [ContextTransitionFrame: 000000000dccf768]

This returns the full stack with a lot of frames that we’re not really interested in. What we’re looking for is the first instance of an HttpContext. If we start from the bottom and work our way up, this seems to be the first time an HttpContext is present:

000000000dcce820 000007fedb704c8e System.Web.HttpRuntime.ProcessRequestNotificationPrivate(System.Web.Hosting.IIS7WorkerRequest, System.Web.HttpContext)
    PARAMETERS:
        this (0x000000000dcce8c0) = 0x00000000fff3fb20
        wr (0x000000000dcce8c8) = 0x00000000fffa5eb0
        context (0x000000000dcce8d0) = 0x00000000fffa6040

Knowing that the HttpContext contains a reference to an HttpRequest, and that HttpRequest contains the RawUrl string value, we’ll start digging in. Start out by dumping the HttpContext object using the !do command:

0:020> !do 0x00000000fffa6040

Name:        System.Web.HttpContext
MethodTable: 000007fedb896398
EEClass:     000007fedb4882e0
Size:        416(0x1a0) bytes
File:        C:\Windows\Microsoft.Net\assembly\GAC_64\System.Web\v4.0_4.0.0.0__b03f5f7f11d50a3a\System.Web.dll
Fields:
              MT    Field   Offset                 Type VT     Attr            Value Name
000007fedb897c80  40010a3        8 ...IHttpAsyncHandler  0 instance 0000000000000000 _asyncAppHandler
000007fedb88e618  40010a4      158         System.Int32  1 instance                0 _asyncPreloadModeFlags
000007feef9fdc30  40010a5      168       System.Boolean  1 instance                0 _asyncPreloadModeFlagsSet
000007fedb895610  40010a6       10 ...b.HttpApplication  0 instance 00000000fffa8a50 _appInstance
000007fedb897ce8  40010a7       18 ....Web.IHttpHandler  0 instance 00000003fff28c20 _handler
000007fedb898170  40010a8       20 ...m.Web.HttpRequest  0 instance 00000000fffa61f8 _request
000007fedb898550  40010a9       28 ....Web.HttpResponse  0 instance 00000000fffa6378 _response
000007fedb893cb0  40010aa       30 ...HttpServerUtility  0 instance 00000003fff27ed8 _server
000007feefa05ac0  40010ab       38 ...Collections.Stack  0 instance 0000000000000000 _traceContextStack
000007fedb8a41d8  40010ac       40 ....Web.TraceContext  0 instance 0000000000000000 _topTraceContext
000007feefa00548  40010ad       48 ...ections.Hashtable  0 instance 00000000fffab198 _items
000007feef9f85e0  40010ae       50 ...ections.ArrayList  0 instance 0000000000000000 _errors
000007feef9fc588  40010af       58     System.Exception  0 instance 0000000000000000 _tempError
...

This contains a lot of fields (some of which I’ve snipped out). The interesting part however, is this line:

000007fedb898170  40010a8       20 ...m.Web.HttpRequest  0 instance 00000000fffa61f8 _request

This contains a pointer to the HttpRequest instance. Let’s try dumping that one:

0:020> !do 00000000fffa61f8 

Name:        System.Web.HttpRequest
MethodTable: 000007fedb898170
EEClass:     000007fedb488c00
Size:        384(0x180) bytes
File:        C:\Windows\Microsoft.Net\assembly\GAC_64\System.Web\v4.0_4.0.0.0__b03f5f7f11d50a3a\System.Web.dll
Fields:
              MT    Field   Offset                 Type VT     Attr            Value Name
000007fedb89aa30  4001150        8 ...HttpWorkerRequest  0 instance 00000000fffa5eb0 _wr
000007fedb896398  4001151       10 ...m.Web.HttpContext  0 instance 00000000fffa6040 _context
...
000007fee6e1dc48  4001165       90           System.Uri  0 instance 00000003fff29588 _url
000007fee6e1dc48  4001166       98           System.Uri  0 instance 0000000000000000 _referrer
000007fedb900718  4001167       a0 ...b.HttpInputStream  0 instance 0000000000000000 _inputStream
000007fedb8c43d0  4001168       a8 ...ClientCertificate  0 instance 0000000000000000 _clientCertificate
000007feefa07e90  4001169       b0 ...l.WindowsIdentity  0 instance 0000000000000000 _logonUserIdentity
000007fedb8d7fd0  400116a       b8 ...ng.RequestContext  0 instance 0000000000000000 _requestContext
000007feef9fc358  400116b       c0        System.String  0 instance 00000000fffa64f0 _rawUrl
000007feefa008b8  400116c       c8     System.IO.Stream  0 instance 0000000000000000 _readEntityBodyStream
000007fedb8d5ac8  400116d      160         System.Int32  1 instance                0 _readEntityBodyMode
000007fedb8bbcb0  400116e       d0 ...atedRequestValues  0 instance 00000003fff27fe8 _unvalidatedRequestValues
...

Once again there are a lot of fields that we don’t care about. The interesting one is this one:

000007feef9fc358  400116b       c0        System.String  0 instance 00000000fffa64f0 _rawUrl

Dumping the RawUrl property reveals the actual URL that made the request which eventually ended up causing a runaway thread:

0:020> !do 00000000fffa64f0 

Name:        System.String
MethodTable: 000007feef9fc358
EEClass:     000007feef363720
Size:        150(0x96) bytes
File:        C:\Windows\Microsoft.Net\assembly\GAC_64\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll
String:      /Catalogs/SomeClient/Uge45/Image.ashx?PageNumber=1&ImageType=Thumb
Fields:
              MT    Field   Offset                 Type VT     Attr            Value Name
000007feef9ff108  40000aa        8         System.Int32  1 instance               62 m_stringLength
000007feef9fd640  40000ab        c          System.Char  1 instance               2f m_firstChar
000007feef9fc358  40000ac       18        System.String  0   shared           static Empty
                                 >> Domain:Value  0000000001ec80e0:NotInit  0000000001f8e840:NotInit

And there we go! The offending URL seems to be:

/Catalogs/SomeClient/Uge45/Image.ashx?PageNumber=1&ImageType=Thumb

If you want the complete URL, including hostname, you could dig your way into the _url field on the HttpRequest object and work your way from there. In just the same way you can dig into pretty much any object, whether it’s in your code or in the IIS codebase.

Apr 30
2013

In part 2 we found out that the concurrent access to a generic dictionary triggered a race condition bug that caused threads to get stuck at 100% CPU usage. In this part, I’ll show how easy it is to rewrite the code, using the new thread-safe dictionaries in .NET 4.0, so it’s protected from race condition bugs like the one I encountered.

Enter ConcurrentDictionary

The problem can be solved by changing just two lines of code. Instead of using a generic Dictionary, we’ll change it to a generic ConcurrentDictionary like so:

private static readonly ConcurrentDictionary<short, ConcurrentDictionary<SettingDescription, SettingDescriptionContainer>> cache =
	new ConcurrentDictionary<short, ConcurrentDictionary<SettingDescription, SettingDescriptionContainer>>();

As described by this MSDN article on adding and removing items from a ConcurrentDictionary, it’s fully thread-safe:

ConcurrentDictionary<TKey, TValue> is designed for multithreaded scenarios. You do not have to use locks in your code to add or remove items from the collection.

Performance wise ConcurrentDictionary is about 50% slower (anecdotally) than the regular Dictionary type but even if this code is run very often, that is absolutely negligible compared to making just a single database access call.

Besides switching the Dictionary out with a ConcurrentDictionary, we also need to modify the init function since the ConcurrentDictionary way of adding items is slightly different:

private static object syncRoot = new object();

private static void init(IPartnerConfig partnerConfig)
{
	// We only want one inside the init method at a time
	lock (syncRoot)
	{
		if (cache.ContainsKey(partnerConfig.PartnerID))
			return;

		var dict = new ConcurrentDictionary<SettingDescription, SettingDescriptionContainer>();

		... // Populate the dict variable with data from the database

		cache.AddOrUpdate(partnerConfig.PartnerID, dict, (k, ov) => dict);
	}
}

The syncRoot lock ensures that only one initialization is going on at the same time. While not necessary in regards of avoiding the race condition, this will avoid hitting the database multiple times if the init method is being called concurrently. This could be optimized in that there could be a syncRoot object per PartnerID to allow concurrently initializing the cache for each PartneriD. But, alas, I opt to keep it simple as the init method is only called once in the lifetime of the application.

Instead of just adding an item to the cache, we have to use the AddOrUpdate() signature that takes in the key, value and a lambda that returns a new value, in case the key already exists in the dictionary. In this case, no matter if the key exists or not, we want to set it to the new value, so the lambda just returns the same value as passed in the second parameter.

Apr 15
2013

Having analyzed the process dump in part 1, let’s take a look at the code we suspect of causing the issue, in particular how race condition bugs can be avoided.

Looking at the User Code

There were three methods in action, all of them in the SettingDescriptionCache class: GetAllDescriptions, init and GetAllDescriptionsAsDictionary. GetAllDescriptions and GetAllDescriptionsAsDictionary are for all intents and purposes identical and both implement a pattern like this:

public static IEnumerable<SettingDescriptionContainer> GetAllDescriptions(IPartnerConfig partnerConfig)
{
	// Optimistic return. If it fails we'll populate the cache and return it.
	try
	{
		return cache[partnerConfig.PartnerID].Values;
	}
	catch (KeyNotFoundException)
	{
		init(partnerConfig);
	}

	return cache[partnerConfig.PartnerID].Values;
}

Both methods access a static variable defined in the class like so:

private static readonly Dictionary<short, Dictionary<SettingDescription, SettingDescriptionContainer>> cache =
	new Dictionary<short, Dictionary<SettingDescription, SettingDescriptionContainer>>();

As this code is being called quite a lot, it’s written using an optimistic pattern that assumes the cache is populated. This is faster than checking if the cache is populated beforehand, or performing a TryGet(). I’ve previously blogged about why you shouldn’t defend against the improbable.

Dictionaries are Not Thread Safe

Looking up the MSDN article on thread-safe collections, you’ll notice the following paragraph describes how the standard Dictionary collections are not thread-safe:

The collection classes introduced in the .NET Framework 2.0 are found in the System.Collections.Generic namespace. These include List<T>, Dictionary<TKey, TValue>, and so on. These classes provide improved type safety and performance compared to the .NET Framework 1.0 classes. However, the .NET Framework 2.0 collection classes do not provide any thread synchronization; user code must provide all synchronization when items are added or removed on multiple threads concurrently.

But is this the issue we’re running into? As there are two dictionaries in action, either one of them could potentially be the culprit. If the partnerConfig.PartnerID value was the same there would be a somewhat higher chance of this really being the issue - but how can find out what PartnerID values were being passed in to the methods?

Analyzing Method Parameters Using Windbg

Back in Windbg, for each of the threads we can run the !CLRStack command once again, but with the -p parameter. This doesn’t just list the stack trace, but also all of the parameters for each frame.

~232s
!CLRStack -p

In the fifth frame, there’s a value for the IPartnerConfig parameter:

iPaper.BL.Backend.Modules.Paper.Settings.SettingDescriptionCache.GetAllDescriptions(iPaper.BL.Backend.Infrastructure.PartnerConfiguration.IPartnerConfig)
	PARAMETERS:
		partnerConfig (0x00000000543ac650) = 0x0000000260a7bd98

The left side value is the local memory address of the pointer itself whilst the right side is the memory location where the actual PartnerConfig instance is stored. By issuing the do (dump object) command, we can inspect the value itself:

!do 0x0000000260a7bd98

If you look under the Name column then you’ll be able to pinpoint the individual fields in the PartnerConfiguration instance. In the Value column you can see that the PartnerID field has a value of 230. Doing this for the other four threads yields the same result - all of them are trying to access the cache value belonging to the PartnerID value of 230!

At this point I can quite confidently say that I’m sure this is a threading issue related to the non thread-safe Dictionary usage. I would’ve expected hard failures like like KeyNotFoundException, NullReferenceException and so on. But apparently, under the exact right race conditions, the dictionaries may get stuck at 100% CPU usage.

Stay tuned for part 3 where I’ll show how to use the Dictionaries in a safe way that avoids issues like these!