5

I'm getting a timeout error when trying to execute a LINQ (-to-SQL) query

System.Data.SqlClient.SqlException: Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding.

Now, this is not just a case of a slow query:

  • I run the equivalent SQL in SQL Management Studio and it completes quickly (2 seconds)
  • I'm setting my CommandTimeout to 2 minutes.
  • When I execute the very same query in a unit test, it completes successfully and quickly. That is: I'm only getting this timeout when I'm running this query alongside other queries. The timeout always occurs at the same call.

That last item made me think that I'm getting some sort of database-side deadlock: the query is blocked by a lock somewhere, and the timeout period elapses, killing the stalled connection.

The trouble with this idea is that I'm only doing selects in the DataContext that's causing problems. (I do have inserts occurring in a different database/DataContexts.) I also have no explicit transactions. This is tripping me up a bit: the query behavior looks exactly like a deadlock, but I've never had a deadlock that wasn't caused by some sort of transaction isolation issue before -- and that doesn't look like the case here (at first glance anyway).

I'm looking for advice on how to debug this problem. What sorts of things should I be looking at to determine the cause of this problem?

EDIT

Some notes that may be useful:

  • I'm querying against a view that references:
    • Other views in the same database
    • Synonyms that point to tables in another database via a Linked Server.
  • This view is using union to join the results of several queries together

EPILOGUE

I ended up fixing the core problem by reworking my query. The original was calling a few tables more than once (via different views). The reworked version bypassed all of this, and the timeouts disappeared.

Craig Walker
  • 49,871
  • 54
  • 152
  • 212
  • when you say 'I run the equivalent SQL in SQL Management Studio' do you mean you are copying the actual sql generated by LINQ from the debugging output? also: since you have access to the database, are you able to isolate and monitor the actual process as it runs in the Activity Monitor? – E Rolnicki Mar 10 '10 at 20:14
  • Have you ran SQL Profiler at the same time as the issue is occurring? – Nicholas Murray Mar 10 '10 at 20:18
  • @E Rolnicki: Yes, getting the actual SQL from LINQ. – Craig Walker Mar 10 '10 at 20:41
  • @E Rolnicki: I'm trying Activity Monitor now... might be on to something as I can see a bunch of locks during the problematic query execution. – Craig Walker Mar 10 '10 at 20:42
  • @Nicholas: I haven't tried SQL profiler just yet. I know what SQL statements I'm executing because I added a logger to the DataContext. If there's other info above this that SQL Profiler could give me, I'd appreciate knowing about it! Profiler is my next stop if Activity Monitor doesn't pan out. – Craig Walker Mar 10 '10 at 20:44
  • is the integration test exactly the same code as the production code? do both the test and the production settings use the same user creds for sql? is there a possibility of something being used for debugging purposes that might be interfering? – E Rolnicki Mar 10 '10 at 20:54
  • @E Rolnicki: I'm definitely not sure of that, and that would be a good candidate for the problem. The question becomes: how does one go about checking for that? (Hrm... the comment I was responding to here seems to have disappeared) – Craig Walker Mar 10 '10 at 20:56
  • @E Rolnicki (re: test/prod code): Yes, the call is exactly the same, and are using the same credentials. I don't think there's any debugging issues in the prod code that could be causing this. – Craig Walker Mar 10 '10 at 20:58
  • not running single-user mode? comment that i removed was about deferred query execution. if the code is the same in both test/production then this will not matter. – E Rolnicki Mar 10 '10 at 21:06
  • @E Rolnicki: nope, not in single-user mode. – Craig Walker Mar 10 '10 at 21:10
  • It's a shame you didn't get an answer for this as I am seeing exactly the same problem. I can recreate it in LinqPad too. The generated SQL runs in less than a second but run from linqpad it times out after 30s – Chris Simpson Sep 07 '10 at 20:37

2 Answers2

4

run your code again from the application, while it is waiting (for 2 minutes??) run this in a query window:

;with Blockers AS
(SELECT
     r.session_id AS spid
         ,r.cpu_time,r.reads,r.writes,r.logical_reads 
         ,r.blocking_session_id AS BlockingSPID
         ,LEFT(OBJECT_NAME(st.objectid, st.dbid),50) AS ShortObjectName
         ,LEFT(DB_NAME(r.database_id),50) AS DatabaseName
         ,s.program_name
         ,s.login_name
         ,OBJECT_NAME(st.objectid, st.dbid) AS ObjectName
         ,SUBSTRING(st.text, (r.statement_start_offset/2)+1,( (CASE r.statement_end_offset
                                                                   WHEN -1 THEN DATALENGTH(st.text)
                                                                   ELSE r.statement_end_offset
                                                               END - r.statement_start_offset
                                                              )/2
                                                            ) + 1
                   ) AS SQLText
     FROM sys.dm_exec_requests                          r
         JOIN sys.dm_exec_sessions                      s ON r.session_id = s.session_id
         CROSS APPLY sys.dm_exec_sql_text (sql_handle) st
     --WHERE r.session_id > 50
)
SELECT Blockers.* FROM Blockers

it will show you all the blocks at the time of the run.

KM.
  • 101,727
  • 34
  • 178
  • 212
  • That's a cool query, but I don't think I'm getting useful information from it. When I run it during the "pause" of query execution before the timeout, I get 2 rows. One is for this query itself, and the other is for the query causing the timeout. On the latter, I get a BlockingSPID of 0, and I don't see any other info in the row that would indicate what's being blocked. – Craig Walker Mar 10 '10 at 20:49
  • that means you NOT are waiting for a lock, which is the `useful` – KM. Mar 23 '10 at 11:26
0

Are you sure the connection pool isn't being eaten up by uncollected resources?

Try wrapping your SqlDataContext in a using block and see if the issue persists.

Gabriel Isenberg
  • 25,869
  • 4
  • 37
  • 58
  • My DataContext is already in a using block, but it's lifetime is being stretched over many dozens of queries (ie: the lifetime of the app). How can I check to see what uncollected resources exist? – Craig Walker Mar 10 '10 at 20:30