Sorry for the repost; this post made it live (and into my Google Reader history), and then mysteriously disappeared from my BlogEngine.NET installation on GoDaddy. I suspect somebody quietly restored my database from backup without 'fessing up. Anyway:

This issue’s really annoying. It’ll drive our users nuts. Defining the issue precisely was pretty interesting, though. I haven’t found the right set of google search terms to find others who’ve run into or analysed this problem yet; hopefully this will help someone else.

The background

SSRS is a reporting framework from Microsoft.

• SSRS WinForms ReportViewer sits inside our WinForms client-side application.
• It talks via Web Services to the SSRS middle tier hosted in IIS on our app servers.
• SSRS middle tier stores report metadata and in-flight request information in databases in SQL Server (ReportServer and ReportServerTempDb)
• SSRS middle tier generates reports off our reporting schema in a (separate) SQL Server database.

The scenario

You’re using SQL Server Reporting Services 2005 or 2008. You’re displaying reports by hosting the SSRS WinForms ReportViewer control inside your UI.

You launch a long-running report, and the “Report is being generated” message is displayed.

You realise you chose the wrong set of report parameters, so you press the red “Stop” button to cancel report generation:

Note that at this point, the long-running SQL Server call to get the report data is still running on the server-side.

You amend your report parameters and press “View report” again:

The eagle-eyed will notice that nothing’s changed. The user is given no feedback that the second "View report” command is being processed. Even worse, the UI thread is actually completely blocked, waiting for a call to the SSRS server to complete.

Investigation

How can this be happening? The ReportViewer seems to do the server call to get report data on a background thread, so that it can give us the nice hourglass from the first screenshot above, and yet the second call’s blocking the UI thread horribly.

If we re-run the test and pause the debugger while the UI thread’s blocked after the second “View report” command’s issued, we see the following threads:

And the main (UI) thread has the following call stack:

• [Managed to Native Transition]   
• System.dll!System.Net.Sockets.Socket.Receive(byte[] buffer = {byte[4096]}, int offset = 0, int size, System.Net.Sockets.SocketFlags socketFlags = None, out System.Net.Sockets.SocketError errorCode = Success) + 0xc4 bytes   
• System.dll!System.Net.Sockets.Socket.Receive(byte[] buffer, int offset, int size, System.Net.Sockets.SocketFlags socketFlags) + 0x20 bytes   
• System.dll!System.Net.Sockets.NetworkStream.Read(byte[] buffer, int offset, int size) + 0x84 bytes   
• System.dll!System.Net.PooledStream.Read(byte[] buffer, int offset, int size) + 0x1b bytes   
• System.dll!System.Net.Connection.SyncRead(System.Net.HttpWebRequest request = {System.Net.HttpWebRequest}, bool userRetrievedStream = true, bool probeRead = true) + 0x12a bytes   
• System.dll!System.Net.Connection.PollAndRead(System.Net.HttpWebRequest request, bool userRetrievedStream) + 0x5a bytes   
• System.dll!System.Net.ConnectStream.PollAndRead(bool userRetrievedStream) + 0x1b bytes   
• System.dll!System.Net.HttpWebRequest.EndWriteHeaders(bool async) + 0xa2 bytes   
• System.dll!System.Net.HttpWebRequest.WriteHeadersCallback(System.Net.WebExceptionStatus errorStatus, System.Net.ConnectStream stream = {System.Net.ConnectStream}, bool async) + 0x16 bytes   
• System.dll!System.Net.ConnectStream.WriteHeaders(bool async) + 0x2d1 bytes   
• System.dll!System.Net.HttpWebRequest.EndSubmitRequest() + 0x82 bytes   
• System.dll!System.Net.HttpWebRequest.SetRequestSubmitDone(System.Net.ConnectStream submitStream) + 0xf7 bytes   
• System.dll!System.Net.Connection.CompleteConnection(bool async, System.Net.HttpWebRequest request = {System.Net.HttpWebRequest}) + 0x158 bytes   
• System.dll!System.Net.Connection.CompleteStartConnection(bool async, System.Net.HttpWebRequest httpWebRequest) + 0x177 bytes   
• System.dll!System.Net.Connection.CompleteStartRequest(bool onSubmitThread, System.Net.HttpWebRequest request = {System.Net.HttpWebRequest}, System.Net.TriState needReConnect = True) + 0x9a bytes   
• System.dll!System.Net.Connection.SubmitRequest(System.Net.HttpWebRequest request = {System.Net.HttpWebRequest}) + 0x293 bytes   
• System.dll!System.Net.ServicePoint.SubmitRequest(System.Net.HttpWebRequest request = {System.Net.HttpWebRequest}, string connName = "S>System.Net.NegotiateClient/25/S") + 0x7c bytes   
• System.dll!System.Net.HttpWebRequest.SubmitRequest(System.Net.ServicePoint servicePoint) + 0xf9 bytes   
• System.dll!System.Net.HttpWebRequest.GetResponse() + 0x270 bytes   
• System.Web.Services.dll!System.Web.Services.Protocols.WebClientProtocol.GetWebResponse(System.Net.WebRequest request) + 0xd5 bytes   
• System.Web.Services.dll!System.Web.Services.Protocols.HttpWebClientProtocol.GetWebResponse(System.Net.WebRequest request) + 0x5 bytes   
• Microsoft.ReportViewer.Common.dll!Microsoft.SqlServer.ReportingServices2005.Execution.RSExecutionConnection.GetWebResponse(System.Net.WebRequest request) + 0xe bytes   
• Microsoft.ReportViewer.WinForms.dll!Microsoft.Reporting.WinForms.ServerReportSoapProxy.GetWebResponse(System.Net.WebRequest request) + 0x10 bytes   
• System.Web.Services.dll!System.Web.Services.Protocols.SoapHttpClientProtocol.Invoke(string methodName, object[] parameters) + 0xad bytes   
• Microsoft.ReportViewer.Common.dll!Microsoft.SqlServer.ReportingServices2005.Execution.ReportExecutionService.SetExecutionParameters(Microsoft.SqlServer.ReportingServices2005.Execution.ParameterValue[] Parameters, string ParameterLanguage) + 0x42 bytes   
• Microsoft.ReportViewer.Common.dll!Microsoft.SqlServer.ReportingServices2005.Execution.RSExecutionConnection.SetExecutionParameters(Microsoft.SqlServer.ReportingServices2005.Execution.ParameterValue[] Parameters, string ParameterLanguage) + 0x42 bytes   
• Microsoft.ReportViewer.WinForms.dll!Microsoft.Reporting.WinForms.ServerReport.SetParameters(System.Collections.Generic.IEnumerable<Microsoft.Reporting.WinForms.ReportParameter> parameters) + 0x2a1 bytes   
• Microsoft.ReportViewer.WinForms.dll!Microsoft.Reporting.WinForms.RSParams.SaveControlValuesToReport() + 0x309 bytes   
• Microsoft.ReportViewer.WinForms.dll!Microsoft.Reporting.WinForms.RSParams.viewReport_Click(object sender, System.EventArgs e) + 0x57 bytes   
• System.Windows.Forms.dll!System.Windows.Forms.Control.OnClick(System.EventArgs e) + 0x70 bytes   
• System.Windows.Forms.dll!System.Windows.Forms.Button.OnClick(System.EventArgs e) + 0x4a bytes   
• System.Windows.Forms.dll!System.Windows.Forms.Button.OnMouseUp(System.Windows.Forms.MouseEventArgs mevent = {X = 44 Y = 3 Button = Left}) + 0xac bytes   
• System.Windows.Forms.dll!System.Windows.Forms.Control.WmMouseUp(ref System.Windows.Forms.Message m, System.Windows.Forms.MouseButtons button, int clicks) + 0x28f bytes   
• System.Windows.Forms.dll!System.Windows.Forms.Control.WndProc(ref System.Windows.Forms.Message m) + 0x885 bytes   
• System.Windows.Forms.dll!System.Windows.Forms.ButtonBase.WndProc(ref System.Windows.Forms.Message m) + 0x127 bytes   
• System.Windows.Forms.dll!System.Windows.Forms.Button.WndProc(ref System.Windows.Forms.Message m) + 0x20 bytes   
• System.Windows.Forms.dll!System.Windows.Forms.Control.ControlNativeWindow.OnMessage(ref System.Windows.Forms.Message m) + 0x10 bytes   
• System.Windows.Forms.dll!System.Windows.Forms.Control.ControlNativeWindow.WndProc(ref System.Windows.Forms.Message m) + 0x31 bytes   
• System.Windows.Forms.dll!System.Windows.Forms.NativeWindow.Callback(System.IntPtr hWnd, int msg = 514, System.IntPtr wparam, System.IntPtr lparam) + 0x5a bytes   
• [Native to Managed Transition]   
• [Managed to Native Transition]   
• System.Windows.Forms.dll!System.Windows.Forms.Application.ComponentManager.System.Windows.Forms.UnsafeNativeMethods.IMsoComponentManager.FPushMessageLoop(int dwComponentID, int reason = -1, int pvLoopData = 0) + 0x24e bytes   
• System.Windows.Forms.dll!System.Windows.Forms.Application.ThreadContext.RunMessageLoopInner(int reason = -1, System.Windows.Forms.ApplicationContext context = {System.Windows.Forms.ApplicationContext}) + 0x177 bytes   
• System.Windows.Forms.dll!System.Windows.Forms.Application.ThreadContext.RunMessageLoop(int reason, System.Windows.Forms.ApplicationContext context) + 0x61 bytes   
• System.Windows.Forms.dll!System.Windows.Forms.Application.Run(System.Windows.Forms.Form mainForm) + 0x31 bytes   
• >    WindowsFormsApplication4.exe!WindowsFormsApplication4.Program.Main() Line 20 + 0x1d bytes    C#
• [Native to Managed Transition]   
• [Managed to Native Transition]   
• mscorlib.dll!System.AppDomain.ExecuteAssembly(string assemblyFile, System.Security.Policy.Evidence assemblySecurity, string[] args) + 0x3a bytes   
• Microsoft.VisualStudio.HostingProcess.Utilities.dll!Microsoft.VisualStudio.HostingProcess.HostProc.RunUsersAssembly() + 0x2b bytes   
• mscorlib.dll!System.Threading.ThreadHelper.ThreadStart_Context(object state) + 0x66 bytes   
• mscorlib.dll!System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, object state) + 0x6f bytes   
• mscorlib.dll!System.Threading.ThreadHelper.ThreadStart() + 0x44 bytes   

From the bolded lines, reading from the bottom up, we can see:

• this thread’s pumping messages (RunMessageLoop), so it’s likely to be a UI thread;
• it’s handling a button click on the ViewReport button (OnClick and viewReport_Click), so it is likely to be the blocked UI thread that’s causing us grief;
• it’s making a synchronous Web Services call to the Report Server (via a proxy) to a method called “SetExecutionParameters”

So in reality, SSRS is actually making at least two Web Services calls to the Report Server. The first is a UI-blocking synchronous call to SetExecutionParameters, and the second is an asynchronous call to do the actual report generation.

Because the first click on “View Report” didn’t block the UI and in fact jumped straight to the friendly hourglass UI mode, we can infer that SetExecutionParameters either wasn’t called first time through, or it was called and was so fast that we didn’t notice the blocking.

While the UI’s blocked, let’s go the SQL Server and get a list of locks that processes are waiting on in either of our SSRS databases:

select *
from sys.dm_tran_locks  l
where resource_type = 'KEY' and request_status <> 'GRANT'
order by resource_database_id, request_owner_id, request_request_id

So, somebody’s waiting for a LOCK on a KEY resource (roughly, a particular value in an index) with resource_associated_entity_id = 72057594038386688. What does that number correspond to?

Okay, somebody’s waiting on a lock on a KEY value in the SessionLock table in ReportServerTempDb. Sure looks as if there’s a session-level lock, and the first report generation server call is holding that lock while the second “SetExecutionParameters” request waits for it to complete. Because (and this is the whole point of supporting cancellation) that first generation call is taking a very long time to complete, the user’s going to be stuck waiting for a very long time, with the UI completely hung, before the second request is cancellable and actually commences the real work of generating report results.

This sucks.

Analysis

While it looks like the SSRS WinForms ReportViewer control has a nice asynchronous design that avoids blocking the UI thread, it still blocks in exactly the situation where it’s most irritating.

• SSRS has a SessionLock which serializes certain operations at a per-Session level.
• SetExecutionParameters and report generation both require the SessionLock, so can’t run concurrently for a given session.
• The SSRS team didn’t find and implement a reliable way to cancel an in-flight request before processing a second request.
• So if a long-running report generation process kicks off, any subsequent requests from that session will have to wait until the first request dies or completes.
• SSRS backgrounds the report generation call. This is good; users get feedback that something’s happening, and the UI thread’s not blocked, so the rest of the application is still usable.
• SSRS mistakenly assumes that “SetExecutionParameters” will never be long-running, so doesn’t background it. This assumption is wrong, because it can be blocked by an earlier report generation call that’s still running. When this happens, the UI thread’s blocked, and the client’s application hangs completely. User experience sucks.

Workarounds

1. Do nothing.
2. Write your own ReportViewer alternative that backgrounds all potentially long-running server calls. A lot of work, I know.
3. Hide the Stop button (set the ShowStopButton property to false on the ReportViewer instance) and provide your own Stop button outside of the control. This external stop button then resets or even re-instantiates the control completely, causing a new user session to be created, so there’s no contention on SessionLock, so the user experience is improved. ReportViewer property values that were previously set in the designer will have to be re-applied. Horrible, I know.
4. Hook the ReportViewer’s RenderingComplete event. Check RenderingCompleteEventArgs for an exception whose message contains “the operation was canceled”. If that exception’s present, then assume the user clicked “Stop”. Re-create or Reset() the Report viewer. Horrible, I know.

We’re likely to go with option 4 at this point.