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.

The post Could Not Load Type ‘NewRelic.Agent.Core.AgentApi’ appeared first on Mark S. Rasmussen - Blog.

The Scenario

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

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.

The post Partial DNS Forwarding Using Individual Windows DNS Zones appeared first on Mark S. Rasmussen - Blog.

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 :)

The post OrcaMDF Is Now Available on NuGet appeared first on Mark S. Rasmussen - Blog.

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.

The post How to Identify Which Request Caused a Runaway Thread, Using Windbg appeared first on Mark S. Rasmussen - Blog.

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 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.

The post Debugging in Production Part 3 – Thread-Safe Dictionaries appeared first on Mark S. Rasmussen - Blog.

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, Dictionary, 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!

The post Debugging in Production Part 2 – Latent Race Condition Bugs appeared first on Mark S. Rasmussen - Blog.

I cannot recommend attending SQLSaturdays enough, especially so if they’re close to you. Whether you’re a SQL Server or .NET developer, DBA or a BI person, there’s relevant content for you. Looking beyond the schedule, SQLSaturdays are excellent networking opportunities where people from very different business areas meet and mingle.

If you want to go all in, there’s even three precons on Friday the 19th of April – one of which I’m presenting, the other two by Denny Cherry and Jen Stirrup. You can see the lineup and register here.

The post Last Chance to Register for SQLSaturday #196 in Copenhagen appeared first on Mark S. Rasmussen - Blog.

The Symptom

Some HTTP requests were being rejected by one of our servers with status 503 indicating that the request queue limit had been reached. Looking at the CPU usage, it was clear why this was happening.

Initially I fixed the issue by issuing an iisreset, clearing the queue and getting back to normal. But when this started occurring on multiple servers at random times, I knew there was something odd going on.

Isolating the Server and Creating a Dump

To analyze what’s happening, I needed to debug the process on the server while it was going on. So I sat around and waited for the next server to act up, and sure enough, within a couple of hours another one of our servers seemed to be stuck at 100% CPU. Immediately I pulled it out of our load balancers so it wasn’t being served any new requests, allowing me to do my work without causing trouble for the end users.

In server 2008 it’s quite easy to create a dump file. Simply fire up the task manager, right click the process and choose “Create Dump File”.

Do note that task manager comes in both an x64 and an x86 version. If you run the x64 version and make a dump of an x86 process, it’ll still create an x64 dump, making it unusable. As such, make sure you use whatever task manager that matches the architecture of the process you want to dump. On an x64 machine (with Windows on the C: drive) you can find the x86 task manager here: C:\Windows\SysWOW64\taskmgr.exe. Note that you can’t run both at the same time, so make sure to close the x64 taskmgr.exe process before starting the x86 one.

Once the dump has been created, a message will tell you the location of the .DMP file. This is roughly twice the size of the process at the time of the dump, so make sure you have enough space on your C: drive.

Finding the Root Cause Using Windbg

Now that we have the dump, we can open it up in Windbg and look around. You’ll need to have Windbg installed in the correct version (it comes in both x86 and x64 versions). While Windbg can only officially be installed as part of the whole Windows SDK, Windbg itself is xcopy deploy-able, and is available for download here.

To make things simple, I just run Windbg on the server itself. That way I won’t run into issues with differing CLR versions being installed on the machine, making debugging quite difficult.

Once Windbg is running, press Ctrl+D and open the .DMP file.

The first command you’ll want to execute is this:

!loadby sos clr

This loads in the Son of Strike extension that contains a lot of useful methods for debugging .NET code.

Identifying Runaway Threads

As we seem to have a runaway code issue, let’s start out by issuing the following command:

!runaway

This lists all the threads as well as the time spent executing user mode code. When dealing with a 100% CPU issue, you’ll generally see some threads chugging away all the time. In this case it’s easy to see that looking at just the top four threads, we’ve already spent over 20 (effective) minutes executing user mode code – these threads would probably be worth investigating.

Analyzing CLR Stacks

Now that we’ve identified some of the most interesting threads, we can select them one by one like so:

~Xs

Switching X out with a thread number (e.g. 234, 232, 238, 259, 328, etc.) allows us to select the thread. Notice how the lower left corner indicates the currently selected thread:

Once selected, we can see what the thread is currently doing by executing the following command:

!CLRStack

Looking at the top frame in the call stack, it seems the thread is stuck in the BCL Dictionary.FindEntry() method:

System.Collections.Generic.Dictionary`2[[System.Int16, mscorlib],[System.__Canon, mscorlib]].FindEntry(Int16)

Tracing back just a few more frames, this seems to be invoked from the following user function:

iPaper.BL.Backend.Modules.Paper.Settings.SettingDescriptionCache.GetAllDescriptions()

Performing the same act for the top five threads yields a rather clear unanimous picture:

234:
System.Collections.Generic.Dictionary`2[[System.Int16, mscorlib],[System.__Canon, mscorlib]].FindEntry(Int16)
...
iPaper.BL.Backend.Modules.Paper.Settings.SettingDescriptionCache.GetAllDescriptions(iPaper.BL.Backend.Infrastructure.PartnerConfiguration.IPartnerConfig)
 
232:
System.Collections.Generic.Dictionary`2[[System.Int16, mscorlib],[System.__Canon, mscorlib]].Insert(Int16, System.__Canon, Boolean)
...
iPaper.BL.Backend.Modules.Paper.Settings.SettingDescriptionCache.init(iPaper.BL.Backend.Infrastructure.PartnerConfiguration.IPartnerConfig)
 
238:
System.Collections.Generic.Dictionary`2[[System.Int16, mscorlib],[System.__Canon, mscorlib]].FindEntry(Int16)
...
iPaper.BL.Backend.Modules.Paper.Settings.SettingDescriptionCache.GetAllDescriptions(iPaper.BL.Backend.Infrastructure.PartnerConfiguration.IPartnerConfig)
 
259:
System.Collections.Generic.Dictionary`2[[System.Int16, mscorlib],[System.__Canon, mscorlib]].FindEntry(Int16)
...
iPaper.BL.Backend.Modules.Paper.Settings.SettingDescriptionCache.GetAllDescriptions(iPaper.BL.Backend.Infrastructure.PartnerConfiguration.IPartnerConfig)
 
328:
System.Collections.Generic.Dictionary`2[[System.Int16, mscorlib],[System.__Canon, mscorlib]].FindEntry(Int16)
...
iPaper.BL.Backend.Modules.Paper.Settings.SettingDescriptionCache.GetAllDescriptionsAsDictionary(iPaper.BL.Backend.Infrastructure.PartnerConfiguration.IPartnerConfig)

Interestingly, all of the threads are stuck inside internal methods in the base class library Dictionary class. All of them are invoked from the user SettingDescriptionCache class, though from different methods.

Stay tuned for part 2 where we’ll dive into the user code and determine what’s happening!

The post Debugging in Production Part 1 – Analyzing 100% CPU Usage Using Windbg appeared first on Mark S. Rasmussen - Blog.

What’s especially unusual about this is that Chrome has a built-in Flash player, so if anyone, Chrome users should be able to view Flash content. Digging deeper I found that the built-in Flash player extension had been disabled. To check if that’s the case, see here:

Chrome Settings => Show advanced settings... => Privacy => Content settings... => Plug-ins => Disable individual plug-ins...

By just clicking “Enable”, everything is working again. But how did it get disabled? This is such a convoluted place to find that I know the users haven’t done so themselves. Looking at Twitter, it seems we’re not alone in seeing this:

I wonder why my Chrome Flash Player plugin suddenly disabled itself whilst I was listening to the radio; very odd. Enabled & all seems fine.

— Gill (@AnandaWoW) 27. feb. 2013

but sorted it out :3 stupid chrome had adobe flash player listed as ‘disabled’ -.- which is stupid cause flash player runs everything D:

— BazingaofSuburbia (@RachofSuburbia) 26. feb. 2013

Crisis averted. Turns out the flash player in Chrome had been disabled. Video watching can now commence :)

— Lin (@linnysvault) 26. feb. 2013

@astracius And all sorted thanks to Chrome being awesome (no idea how Flash was disabled though).

— David Wilson (@Astracius) 26. feb. 2013

@kevinmenzel nah, just realized flash somehow got disabled in google chrome. but thank you

— junctionette (@junctionette) 26. feb. 2013

Who the fuck went on the computer and disabled Flash on Google Chrome? Why would someone do that? That was annoying.

— Nathan. (@envyonthetoast) 26. feb. 2013

… I think you get the picture. It seems that all of our users had just had their Flash player auto update itself. I’m wondering, could the Internet Explorer Flash plugin perhaps updated itself and, by mistake, disabled the Chrome plugin? If the built-in Chrome Flash player is disabled, Chrome will try to use the regular Flash plugin. However, the Internet Explorer version won’t work in Chrome, so that won’t work.

Anyone else experienced this? Any tips on what’s causing it? The fix is simple, but I’d really like to understand what’s causing this, as well as knowing how widespread the issue is.

The post Native Chrome Flash Player Disabled by Itself All of a Sudden appeared first on Mark S. Rasmussen - Blog.

Having just about 100 people attend my Top X SQL Server Developer Mistakes session at Warm Crocodile recently made me realize just how popular SQL Server really is. Nosql might be the hype, but when it comes to business, quite a lot of developers are “stuck” with SQL Server on a daily basis. For the same reason, I absolutely cannot recommend going to SQLSaturday #196 enough! It’s free, it’s an excellent networking opportunity and it’s sure to be full of great speakers and content. Go ahead – register here!

I’ll have the pleasure and honor of presenting my A Deep Dive Into the Depths of the SQL Server Storage Engine and MDF File Format precon on the 19th of April, the day before the SQLSaturday event itself. It’s not the first time I’m presenting this precon, in fact, this’ll be my fifth time. This means I’ve now had a number of chances to test my content and optimize the format to ensure you get maximum value out of the day. If you’re planning on attending and have any special requests or questions regarding the content, please do let me know in the comments here!

If storage internals isn’t your thing, there are two other top notch presenters – Jen Stirrup and Denny Cherry. Jen will be presenting a Data Visualisation Deep-Dive using SQL Server 2012 while Denny will present on SQL Server 2012 in a Highly Available World.

The post SQLSaturday #196 – Presenting a Precon appeared first on Mark S. Rasmussen - Blog.

I first launched the blog back in 2002, though it was in Danish back then. In 2006 I decided to start over, removed all my Danish content and began blogging in English – at that time, I wrote my own blog engine in a couple of days on a couch in Henderson, Nevada, anxiously waiting to turn 21 so I could participate in the World Series of Poker.

Back in 2011 I chose to migrate all my content onto Subtext. What I failed to notice was that the project was pretty much dead, so it was a migration doomed to be still born. It did however allow me access to Windows Live Writer which served its purpose – it got me blogging again due to its simplicity in use. However, I quickly started to struggle with Subtext as templating was beyond difficult and I had to resort to ugly hacks to make it work the best I could.

And so it was time for yet another revamp, this time, hopefully the last. Converting everything into WordPress ought to be a simple task, if it wasn’t for the fact that I had almost 250 posts and 700 comments. Most of them stemming from my homebrewed system, later haphazardly migrated to Subtext, and now lying before WordPress. I had to write a custom exporter to get most of my content from Subtext into the WordPress WXR format. Dealing with attachments, encoding and comments was a major pain. Once I had everything into WordPress, I had to go through each and every post and manually format the contents – having seven years of legacy left little to no structure, making it impossible to style.

At this point, all I needed to do was to find a good theme and I was up and running. Unfortunately I tend to be quite picky, so I couldn’t find anything I really liked. In the end, I ended up writing my own theme, which I’ve just published to Github. My main priority has been to create a very simplistic theme that worked great across devices, while allowing me to post easily readable code snippets. If you have any suggestions for improvements, I’d love to hear them!

The post Blog Revamp appeared first on Mark S. Rasmussen - Blog.

Both slides, demos and source samples are available on Github:
https://github.com/improvedk/Presentation-TopXSQLServerDeveloperMIstakes

The post Top X SQL Server Developer Mistakes appeared first on Mark S. Rasmussen - Blog.

Today I can no longer use that introduction, as I’ve been awarded as a Microsoft MVP (SQL Server) for 2013. I’m honored to receive the award, but mostly, I’m thankful to my friends in the SQL Family.

The last couple of years have been busy, 2012 definitely taking the cake, by my standards. Through my SQL Server engagement I’ve made countless of friends across the world – The Netherlands, Slovenia, Denmark, Germany, Austria, Sweden, all over the US, South Africa, UK, and many more. I remember how my parents worried about how you couldn’t make friends through the computer… While generally being right, on this point, they were not.

As 2012 neared its end, I also promised myself that I would slow down a tad in 2013. I will still try to keep that promise. I simply cannot afford to travel around as much as I did last year, and I really want to trade just a bit of conference travel for pure leisure travel time. However, this doesn’t mean I’ll go into hibernation for the duration of 2012. Currently I’m scheduled to be presenting at the Warm Crocodile conference in Copenhagen on January 17th and I know I’ll do my utmost to attend the PASS Summit this year, having missed it in 2012. What else 2013 will bring, time will tell :)

The post And Thus I Lost My Introduction appeared first on Mark S. Rasmussen - Blog.

However, I don’t want to just list the stored procedures, I also want to present the source code in them. That brings up a new task – retrieving said source code. Where is it stored? I wasn’t able to find anything on Google, so let’s take a look for ourselves!

I’ve created a new empty database with a data file of three megabytes. In this database, I’ve created a single stored procedure like so:

SET ANSI_NULLS ON
GO
SET QUOTED_IDENTIFIER ON
GO
-- =============================================
-- Author:		
-- Create date: 
-- Description:	
-- =============================================
CREATE PROCEDURE XYZ
	AS
BEGIN
	-- SET NOCOUNT ON added to prevent extra result sets from
	-- interfering with SELECT statements.
	SET NOCOUNT ON;
 
    -- Insert statements for procedure here
	SELECT 'AABBCC' AS Output
END

Now when I select from sys.procedures, we can see that the procedure has object ID 2105058535:

select * from sys.procedures

So far so good. We can then retrieve the definition itself as an nvarchar(MAX) by querying sys.sql_modules like so:

select * from sys.sql_modules where object_id = 2105058535

And there you have it, the source code for the XYZ procedure! But hold on a moment, while I’ve gotten the object ID for the procedure by querying the sys.sysschobjs base table, I don’t have access to sys.sql_modules yet, as that’s a view and not a base table. Let’s take a look at where sys.sql_modules gets the definition from:

select object_definition(object_id('sys.sql_modules'))

SELECT
	object_id = o.id,
	definition = Object_definition(o.id),
	uses_ansi_nulls = Sysconv(bit, o.status & 0x40000), -- OBJMOD_ANSINULLS
	uses_quoted_identifier = sysconv(bit, o.status & 0x80000),   -- OBJMOD_QUOTEDIDENT
	is_schema_bound = sysconv(bit, o.status & 0x20000),    -- OBJMOD_SCHEMABOUND
	uses_database_collation = sysconv(bit, o.status & 0x100000),  -- OBJMOD_USESDBCOLL
	is_recompiled = sysconv(bit, o.status & 0x400000),     -- OBJMOD_NOCACHE
	null_on_null_input = sysconv(bit, o.status & 0x200000),   -- OBJMOD_NULLONNULL
	execute_as_principal_id = x.indepid
FROM
	sys.sysschobjs o
LEFT JOIN
	sys.syssingleobjrefs x ON x.depid = o.id AND x.class = 22 AND x.depsubid = 0 -- SRC_OBJEXECASOWNER
WHERE
	o.pclass <> 100 AND
	(
		(o.type = 'TR' AND has_access('TR', o.id, o.pid, o.nsclass) = 1) OR
		(type IN ('P','V','FN','IF','TF','RF','IS') AND has_access('CO', o.id) = 1) OR
		(type IN ('R','D') AND o.pid = 0)
	)

Hmmm, so sys.sql_modules gets the source by using the object_definition system function. Unfortunately, the following doesn’t work:

select object_definition(object_id('object_definition'))

I happen to remember that sys.sql_modules is a replacement for the, now deprecated, sys.syscomments legacy view. Let’s take a look at where that one gets the source from:

select object_definition(object_id('sys.syscomments'))

SELECT
	o.id AS id,  
	convert(smallint, case when o.type in ('P', 'RF') then 1 else 0 end) AS number,  
	s.colid,
	s.status,  
	convert(varbinary(8000), s.text) AS ctext,  
	convert(smallint, 2 + 4 * (s.status & 1)) AS texttype,  
	convert(smallint, 0) AS language,  
	sysconv(bit, s.status & 1) AS encrypted,  
	sysconv(bit, 0) AS compressed,  
	s.text  
FROM
	sys.sysschobjs o
CROSS APPLY
	OpenRowset(TABLE SQLSRC, o.id, 0) s  
WHERE
	o.nsclass = 0 AND
	o.pclass = 1 AND
	o.type IN ('C','D','P','R','V','X','FN','IF','TF','RF','IS','TR') AND
	has_access('CO', o.id) = 1  
 
UNION ALL  
 
SELECT
	c.object_id AS id,  
	convert(smallint, c.column_id) AS number,  
	s.colid,
	s.status,  
	convert(varbinary(8000), s.text) AS ctext,  
	convert(smallint, 2 + 4 * (s.status & 1)) AS texttype,  
	convert(smallint, 0) AS language,  
	sysconv(bit, s.status & 1) AS encrypted,  
	sysconv(bit, 0) AS compressed,  
	s.text  
FROM
	sys.computed_columns c
CROSS APPLY
	OpenRowset(TABLE SQLSRC, c.object_id, c.column_id) s  
 
UNION ALL  
 
SELECT
	p.object_id AS id,  
	convert(smallint, p.procedure_number) AS number,  
	s.colid,
	s.status,  
	convert(varbinary(8000), s.text) AS ctext,  
	convert(smallint, 2 + 4 * (s.status & 1)) AS texttype,  
	convert(smallint, 0) AS language,  
	sysconv(bit, s.status & 1) AS encrypted,  
	sysconv(bit, 0) AS compressed,  
	s.text  
FROM
	sys.numbered_procedures p
CROSS APPLY
	OpenRowset(TABLE SQLSRC, p.object_id, p.procedure_number) s  
 
UNION ALL  
 
SELECT
	o.id AS id,  
	convert(smallint, case when o.type in ('P', 'RF') then 1 else 0 end) AS number,  
	s.colid,
	s.status,  
	convert(varbinary(8000), s.text) AS ctext,  
	convert(smallint, 2) AS texttype,  
	convert(smallint, 0) AS language,  
	sysconv(bit, 0) AS encrypted,  
	sysconv(bit, 0) AS compressed,  
	s.text  
FROM
	sys.sysobjrdb o
CROSS APPLY
	OpenRowset(TABLE SQLSRC, o.id, 0) s  
WHERE
	db_id() = 1 AND 
	o.type IN ('P','V','X','FN','IF','TF')

Bummer. It doesn’t use object_definition, but instead another internal function in the form of OpenRowset(TABLE SQLSRC, o.id, 0). I’m not one to give up easily though – I’ve previously reverse engineered the OpenRowset(TABLE RSCPROP) function.

Let’s take a different approach to the problem. Everything in SQL Server is stored on 8KB pages in a fixed format. As the procedures aren’t encrypted, they must be stored in clear text somewhere in the database – we just don’t know where. Let’s detach the database and crack open a hex editor (I highly recommend HxD):

Now let’s see if we can find the procedure. On purpose I made it return “SELECT ‘AABBCC’ AS Output” as that would be easy to search for:

And whadda ya know, there it is:

OK, so now we know that the source is stored in the database, just not where specifically. The data is stored at offset 0x00101AF0 in the data file. In decimal, that’s offset 01055472. As each data page is exactly 8KB, we can calculate the ID of the data page that this is stored on (using integer math):

01055472 / 8192 = 128

Aha! At this point we know that the source is stored on page 128 – how about we take a look at that page using DBCC PAGE? After reattaching the database, run:

dbcc traceon (3604)
dbcc page(Test2, 1, 128, 0)

Note that I’m using style 0 for the DBCC PAGE command. At this point, I just want to see the header – there just might be something interesting in there:

As expected, it’s a normal data page, as indicated by the m_type field having a value of 1 (which is the internal page type ID for a data page). More interesting though, we can see that the page belongs to object ID 60! Let’s have a look at what lies behind that object ID:

select * from sys.sysobjects where id = 60

And all of a sudden, the hunt is on! Let’s have a look at the contents of sys.sysobjvalues. Note that before you can select from this table, you’ll have to connect using a dedicated administrator connection, seeing as it’s an internal base table:

select * from sys.sysobjvalues

There’s obviously a lot of stuff in here we don’t care about, but let’s try and filter that objid column down to the object ID of our procedure – 2105058535:

select * from sys.sysobjvalues where objid = 2105058535

I wonder what that imageval column contains, if I remember correctly 0x2D2D would be “–“ in ASCII, which reminds me quite a lot of the beginning of the XYZ procedure. Let’s try and convert that column into human:

select convert(varchar(max), imageval) from sys.sysobjvalues where objid = 2105058535

And there you have it my dear reader; the source code for the XYZ stored procedure, as stored in the sys.sysobjvalues base table. As a final example, here’s how you’d retrieve a list of user stored procedures with their source code, without using neither object_definition nor sys.sql_modules:

select
	p.name,
	cast(v.imageval as varchar(MAX))
from
	sys.procedures p
inner join
	sys.sysobjvalues v on p.object_id = v.objid

Want to see more stuff like this? Don’t miss my full-day precon at SQL Saturday #162 in Cambridge, UK (Friday, September 7th), or my Revealing the Magic session at Bleeding Edge 2012 in Laško, Slovenia (October 23-24th)!

The post Where Does SQL Server Store the Source for Stored Procedures? appeared first on Mark S. Rasmussen - Blog.

This summer, I happened to drop by Ljubljana to visit some friends of mine, as I was in the area on vacation. At some point in the evening, the talk turned to Bleeding Edge again, and before I knew it, Mladen Prajdić said he’d introduce me to one of the organizers, Matija Lah.

Today, I’m excited to announce that I’ll be presenting my Revealing the Magic session at Bleeding Edge 2012 on the 23-24th of October in Laško, Slovenia.

I’ve presented the session before at other venues, and this one will follow the usual fast and furious format. There are 10 hours of content compressed into just one hour. I will be showing the latest OrcaMDF bits during the session and my usual warning goes: This session is not meant to teach as much as it’s meant to inspire you. Inspire you to realize how simple SQL Server really is at its core, once you master the immediate complexity. For a full description of the session, I recommend you go to the Bleeding Edge site.

The post Presenting at Bleeding Edge in Slovenia appeared first on Mark S. Rasmussen - Blog.

The official announcement was made a couple of days ago and I’m embarassingly late to follow up myself. “Unfortunately” this is what I’m doing right now, and I must say that achieving a proper 3G connection in the middle of the Dolomites has proven rather difficult…

Anyways, I’m happy and honored to say that I’ll be presenting my A Deep-Dive into the depths of the SQL Server storage engine and MDF file format  precon at SQLSaturday #162 in Cambridge. I’ll be presenting my precon alongside SQL Server authorities like Jen Stirrup and Buck Woody, not to mention all of the regular session speakers, which have yet to be announced.

Allow me to present some of the feedback I got on my Revealing the Magic session, which is a 1-hour version of my precon, at the last SQLBits:

It was perhaps too much detail to cram into a 1 hour session.

A bit rushed. I can say it is probably the first time I felt my knowledge was not enough to keep up with mark’s content.

Great pace of session – very fast, no messing about – excellent – more sessions should get on with it, like this. Loved the session and very technical – exactly what the benefit of having this stuff delivered face-to-face.

I know he said it at the beginning. but at times it was just too fast. Maybe let the people digest what was said.

I love receiving constructive feedback, and this is so spot on! I definitely need to weed out a bit of content from my 1-hour session as there’s simply too much to go through in just one hour. Having a full day to present the same content is a much more fitting format, and it will allow me to go at a somewhat more normal pace, as well as leaving plenty of time for Q&A during the presentation.

I will however still warn you that this is a level 500 precon. I will go very in depth and there will be plenty of bits and bytes to show – documented as well as undocumented.

Please check out the Cambridgeshire SQL Server User Group page for more information on mine, Jen Stirrup and Buck Woodys precons. Make sure to register, if not for mine then for one of the other excellent precons!

The post Presenting at SQLSaturday #162 in Cambridge appeared first on Mark S. Rasmussen - Blog.

I just got the feedback today – 0 reds, 3 yellows and 15 greens – very happy with that, especially when taking the audience into account. To those of you who haven’t seen my session before, here it is:

Mark S. Rasmussen – Revealing the SQL Server Magic from NDCOslo on Vimeo.

The post Video From NDC 2012: Revealing the SQL Server Magic appeared first on Mark S. Rasmussen - Blog.

Optimizing Storage and Performance Using Page and Row Compression.rar – Slides & demos

Storing Character Data Optimally.rar – Slides & demos

The post 2012 NT Konferenca Slides + Demos appeared first on Mark S. Rasmussen - Blog.

Umbraco was at a split road however, version 4.7 being a widely deployed and tested version, while the brand new 5.0 rewrite had just been released as a release candidate. It was made clear that 5.0 would not be upgradable from previous versions, so I could basically go with 4.7 and be stuck, or go with a release candidate version. To my luck, 5.0 was finally released as RTM before I had to make the decision, rendering my following decision easy – 5.0 was heralded as being production ready.

Performance, oh my

Fast forward a month or so, development well underway. It was clear that there were performance issues. The forums were full of posts asking how to get performance equivalent to what people were used to in 4.7. Unfortunately, there wasn’t really a solution yet. Thankfully 5.1 was released, promising better performance. After spending a couple of days fighting a 5.0 –> 5.1 upgrade bug, I finally got 5.1 running. Much to my dismay, performance was still dismal.

This is me requesting the front page of the website:

1780 individual requests to the database, with several interesting queries like the following:

SELECT this_.Id as Id16_7_, this_.DateCreated as DateCrea2_16_7_, this_.DefaultName as DefaultN3_16_7_,
this_.AttributeSchemaDefinition_id as Attribut4_16_7_, this_.NodeId as NodeId16_7_, attribalia1_.NodeVersionId
as NodeVers3_9_, attribalia1_.Id as Id9_, attribalia1_.Id as Id5_0_, attribalia1_.AttributeDefinitionId as
Attribut2_5_0_, attribalia1_.NodeVersionId as NodeVers3_5_0_, attributed5_.AttributeId as Attribut4_10_,
attributed5_.Id as Id10_, attributed5_.Id as Id1_1_, attributed5_.Value as Value1_1_, attributed5_.ValueKey
as ValueKey1_1_, attributed5_.AttributeId as Attribut4_1_1_, attributed5_.LocaleId as LocaleId1_1_,
attributed6_.AttributeId as Attribut4_11_, attributed6_.Id as Id11_, attributed6_.Id as Id0_2_, attributed6_.Value
as Value0_2_, attributed6_.ValueKey as ValueKey0_2_, attributed6_.AttributeId as Attribut4_0_2_, attributed6_.LocaleId
as LocaleId0_2_, attributei4_.AttributeId as Attribut4_12_, attributei4_.Id as Id12_, attributei4_.Id as
Id3_3_, attributei4_.Value as Value3_3_, attributei4_.ValueKey as ValueKey3_3_, attributei4_.AttributeId
as Attribut4_3_3_, attributei4_.LocaleId as LocaleId3_3_, attributel3_.AttributeId as Attribut4_13_,
attributel3_.Id as Id13_, attributel3_.Id as Id4_4_, attributel3_.Value as Value4_4_, attributel3_.ValueKey as
ValueKey4_4_, attributel3_.AttributeId as Attribut4_4_4_, attributel3_.LocaleId as LocaleId4_4_,
attributes2_.AttributeId as Attribut4_14_, attributes2_.Id as Id14_, attributes2_.Id as Id6_5_, attributes2_.Value
as Value6_5_, attributes2_.ValueKey as ValueKey6_5_, attributes2_.AttributeId as Attribut4_6_5_,
attributes2_.LocaleId as LocaleId6_5_, node14_.Id as Id9_6_, node14_.DateCreated as DateCrea2_9_6_,
node14_.IsDisabled as IsDisabled9_6_, node14_1_.Alias as Alias10_6_, node14_1_.Description as Descript3_10_6_,
node14_1_.Name as Name10_6_, node14_1_.Ordinal as Ordinal10_6_, node14_1_.AttributeSchemaDefinitionId as
Attribut6_10_6_, node14_2_.Alias as Alias11_6_, node14_2_.Description as Descript3_11_6_, node14_2_.Name as
Name11_6_, node14_2_.SchemaType as SchemaType11_6_, node14_2_.XmlConfiguration as XmlConfi6_11_6_, case when
node14_1_.NodeId is not null then 1 when node14_2_.NodeId is not null then 2 when node14_.Id is not null then
0 end as clazz_6_ FROM dbo.NodeVersion this_ left outer join dbo.Attribute attribalia1_ on this_.Id=attribalia1_.NodeVersionId
left outer join dbo.AttributeDecimalValue attributed5_ on attribalia1_.Id=attributed5_.AttributeId left outer join
dbo.AttributeDateValue attributed6_ on attribalia1_.Id=attributed6_.AttributeId left outer join dbo.AttributeIntegerValue
attributei4_ on attribalia1_.Id=attributei4_.AttributeId left outer join dbo.AttributeLongStringValue attributel3_
on attribalia1_.Id=attributel3_.AttributeId left outer join dbo.AttributeStringValue attributes2_ on
attribalia1_.Id=attributes2_.AttributeId inner join dbo.Node node14_ on this_.NodeId=node14_.Id left outer
join dbo.[AttributeDefinitionGroup] node14_1_ on node14_.Id=node14_1_.NodeId left outer join dbo.[AttributeSchemaDefinition]
node14_2_ on node14_.Id=node14_2_.NodeId WHERE this_.Id in (@p0, @p1, @p2, @p3, @p4, @p5, @p6, @p7, @p8,
@p9, @p10, @p11, @p12, @p13, @p14, @p15, @p16, @p17, @p18, @p19, @p20, @p21, @p22, @p23, @p24, @p25, @p26, @p27,
@p28, @p29, @p30, @p31, @p32, @p33, @p34, @p35, @p36, @p37, @p38, @p39, @p40, @p41, @p42, @p43, @p44, @p45, @p46,
@p47, @p48, @p49, @p50, @p51, @p52, @p53, @p54, @p55, @p56, @p57, @p58, @p59, @p60, @p61, @p62, @p63, @p64, @p65,
@p66, @p67, @p68, @p69, @p70, @p71, @p72, @p73, @p74, @p75, @p76, @p77, @p78, @p79, @p80, @p81, @p82, @p83, @p84,
@p85, @p86, @p87, @p88, @p89, @p90, @p91, @p92, @p93, @p94, @p95, @p96, @p97, @p98, @p99, @p100, @p101, @p102, @p103,
@p104, @p105, @p106, @p107, @p108, @p109, @p110, @p111, @p112, @p113, @p114, @p115, @p116, @p117, @p118, @p119, @p120,
@p121, @p122, @p123, @p124, @p125, @p126, @p127, @p128, @p129, @p130, @p131, @p132, @p133, @p134, @p135, @p136, @p137,
... <snip: some 700 other parameters> ...
@p882, @p883, @p884, @p885, @p886, @p887, @p888, @p889, @p890, @p891, @p892, @p893, @p894, @p895, @p896, @p897, @p898,
@p899, @p900, @p901, @p902, @p903, @p904, @p905, @p906, @p907, @p908, @p909, @p910, @p911, @p912, @p913, @p914, @p915,
@p916, @p917, @p918, @p919, @p920, @p921, @p922, @p923, @p924, @p925, @p926, @p927, @p928, @p929, @p930, @p931, @p932,
@p933, @p934, @p935, @p936, @p937, @p938, @p939, @p940, @p941, @p942, @p943, @p944, @p945, @p946, @p947, @p948, @p949,
@p950, @p951, @p952, @p953, @p954, @p955, @p956) and this_.Id in (SELECT this_0_.Id as y0_ FROM dbo.NodeVersion this_0_ WHERE this_0_.NodeId = @p957)

It’s clearly obvious we’re dealing with a serious N+1 problem, made worse by a lack of set based operations as evidenced by the above query. At the same time this query is a ticking time bomb – as soon as it hits the 2100 parameter limit, problems will arise unless they’re handled. The culprit seems to be the fact that the database is queried through a LINQ provider on top of Umbracos own Hive layer, on top of NHibernate. The core team themselves have voiced that NHibernate might be exacerbating the problem as they haven’t tamed the beast completely. I voiced my own concerns and suggestions on the architecture in the main performance thread. Currently the core team seems to be working on a band aid solution; adding a Lucene based cache to the site to improve performance. In my opinion the only way to really solve the issue is to fix the underlying problem – the N+1 one.

Back in January the Umbraco team posted the following: Umbraco 5: On performance and the perils of premature optimization. While I completely agree with the sentiment, avoiding N+1 issues is not premature optimization, that’s a requirement before releasing an RTM product.

The Umbraco team does deserve big kudos on owning up to the problem. They’re painfully aware of the issues people are dealing with, being unable to deploy due to crippling performance. I’m sure they’ll be improving on performance, I just hope it happens sooner than later. I did talk to Niels Hartvig and offered my help (regarding the database layer), should they want it. I’ve also had Alex Norcliffe look at my logs over email – a big thanks goes to the team, helping out even though they’re in a pinch themselves.

Band aid solutions while waiting for 5.2

As I had to get the website up and running for a trade show, I had no choice but to spin up a High-CPU Extra Large Instance on Amazon EC2. While this costs a minor fortune (compared to what hosting the site should’ve required), it gave me a temporary solution for the trade show. Startup times were still terrible but at least requesting pages went reasonably fast, even though some pages did hang for 5+ seconds, depending on the content shown.

Once the trade show was over, I downgraded the EC2 instance to an m1.large instance. It’s still expensive, but it’s a tad cheaper for development. However, there’s a bigger problem looming on the horizon – the site has to go live in a week or two.

The Umbraco team have said they expect a 5.2 performance release sometime during June, and 5.x being on par with 4.7 by the end of 2012. Unfortunately I don’t have the luxury of waiting for that.

What I’ve now done, to prepare for the launch, was to increase the output cache timeout to 24 hours by modifying web.config like so:

<caching>
  <outputCacheSettings>
    <outputCacheProfiles>
      <add name="umbraco-default" duration="86400" varyByParam="*" location="ServerAndClient"/>
    </outputCacheProfiles>
  </outputCacheSettings>
</caching>

This essentially turns the website into a statically cached copy. Doing this results in each page being cached for 24 hours after it’s been visited last. While this is great, it still means those first visitors (for each page on the website) will be suffering from long waits. To fix that, I turn to Xenu’s Link Sleuth. Given the hostname, Xenu will crawl each page on the website, checking for broken links. As a side effect, every page on the site will be visited and thereby cached. By default, Xenu will use 30 concurrent threads to crawl the site. On my EC2 instance, that resulted in loads of timeouts as the instance simply couldn’t handle it:

Pressing Ctrl+R forces Xenu to retry all the failed links, eventually resulting in all the links being visited successfully:

(Sorry for distorting the images – the site isn’t supposed to go completely public yet). For Xenu to find all the links on the site, you’ll have to make sure you’re using <a href /> tags. I had to replace a couple of:

<div onclick="window.open('http://xyz.com')">

With corresponding <a href /> implementations, otherwise Xenu blissfully ignored them.

Obviously fixing the performance issue like this comes with a severe cost – memory usage on the server as well as being unable to update the site from the back office. For now I can live with that as the main priority is getting the site live. When I update I’ll have to manually cycle the app pool as well as rerunning Xenu. Currently the site takes up about 500 megs of memory fully cached, so I’ve got some room to spare.

Thankfully there are no protected parts of the site so user-specific caching is not an issue – YMMV.

The post In the Nick of Time: Band Aid Solution for Umbraco 5.1 Performance appeared first on Mark S. Rasmussen - Blog.

CommunityDay-Using-Amazon-S3-CloudFront-for-Scalable-and-Secure-Distribution.rar – Slides

I also did a demo of OrcaMDF for the following Demo Day happening. You can find more on OrcaMDF here:

Git repository
Blog entries

The post 2012 Community & Demo Day Materials appeared first on Mark S. Rasmussen - Blog.