2

I have a DELETE command that times out when I run it from my application. To investigate I put the same command in SQL Server Management Studio and it executed immediately. Can anybody point me in the right direction to find the cause of the delay?

In SQL Server Management Studio I typed:

DECLARE @docid INT;
SET @docid = 41;
DELETE FROM reports WHERE doc_id=@docid;

The reports table only has 5 rows, 1 of which has a docid of 41.

The reports table is pretty simple:

CREATE TABLE [dbo].[reports](
    [doc_id] [int] NULL,
    [candidate_id] [int] NULL,
    [report] [varbinary](max) NOT NULL,
    [ext] [nvarchar](10) NULL

with some constraints on both ids.

Some more info:

  • If I delete from other tables in the same place it's quite happy.
  • The connection is to a local instance on the same machine.

This is the exception I get when executing from within my application:

{System.Data.SqlClient.SqlException (0x80131904): Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding. ---> System.ComponentModel.Win32Exception (0x80004005): The wait operation timed out at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action1 wrapCloseInAction) at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose) at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady) at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString) at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async, Int32 timeout, Task& task, Boolean asyncWrite, SqlDataReader ds) at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, TaskCompletionSource1 completion, Int32 timeout, Task& task, Boolean asyncWrite) at System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(TaskCompletionSource`1 completion, String methodName, Boolean sendToPipe, Int32 timeout, Boolean asyncWrite) at System.Data.SqlClient.SqlCommand.ExecuteNonQuery()

marc_s
  • 732,580
  • 175
  • 1,330
  • 1,459
noelicus
  • 14,468
  • 3
  • 92
  • 111
  • 1
    Are there any triggers or cascading relationships on the 'reports' table? – jtimperley Aug 13 '14 at 20:44
  • 3
    Possibly a deadlock or circular reference? – Brian Driscoll Aug 13 '14 at 20:46
  • Only these: `ALTER TABLE [dbo].[reports] WITH CHECK ADD CONSTRAINT [FK_reports_candidates] FOREIGN KEY([candidate_id]) REFERENCES [dbo].[candidates] ([candidate_id]) GO ALTER TABLE [dbo].[reports] CHECK CONSTRAINT [FK_reports_candidates] GO ALTER TABLE [dbo].[reports] WITH CHECK ADD CONSTRAINT [FK_reports_documents] FOREIGN KEY([doc_id]) REFERENCES [dbo].[documents] ([docid]) GO ALTER TABLE [dbo].[reports] CHECK CONSTRAINT [FK_reports_documents]` – noelicus Aug 13 '14 at 20:46
  • but the whole database is tiny - only a few rows in each table. the only "big" bit is the `report` column which is binary data. – noelicus Aug 13 '14 at 20:46
  • 1
    Do you have multiple connections in your program, with another one possibly reading data from the table? – zmbq Aug 13 '14 at 20:49
  • Hmmm, probably...will check. – noelicus Aug 13 '14 at 20:49
  • 1
    Try `SELECT * FROM SYS.SYSPROCESSES` and see if any are blocked (while your app is deleting)? If so you can get the code blocking by doing `DBCC INPUTBUFFER(##)` where ## is the SPID of the blocking connection. – Dave C Aug 13 '14 at 20:51
  • Sounds Like Triggers on that particular table try running a sql script to Disable the triggers then Enable them – MethodMan Aug 13 '14 at 20:53
  • 1
    What version of SQL Server and SSMS are you using? SSMS 2008 and above, right click on your connection and select 'Acitvity Monitor'. Any open connections and what state they are in will be listed there. When executing your query it will reference another connection if its blocking. – jtimperley Aug 13 '14 at 20:53
  • Also can you post your app code, and show us how you're connecting/executing the command? – Dave C Aug 13 '14 at 21:02
  • Permissions issue or not cleaning up ADO.NET connection? see: http://stackoverflow.com/questions/18108964/asp-net-web-service-does-not-connect-with-database-in-iis7 see : http://stackoverflow.com/questions/4389506/ado-net-closing-connection-when-using-using-statement – nshah Aug 13 '14 at 21:13
  • Thanks everyone - it was a deadlock where another part of my application had an open `IDataReader` on the reports table. – noelicus Aug 13 '14 at 21:19

2 Answers2

3

You can run this to view all running queries (and the code running), along with the blocking spid details... once you identify the culprit, you can go from there.

You'll need to run this while your app is timing out to get the info correctly.

SET TRANSACTION ISOLATION LEVEL READ UNCOMMITTED
IF OBJECT_ID('TEMPDB..#SPID') IS NOT NULL DROP TABLE #SPID
DECLARE @InputBuffer TABLE (
        ID INT IDENTITY(1,1) PRIMARY KEY,
        SPID INT,
        BLOCKED INT,
        CPU BIGINT,
        PHYSICAL_IO BIGINT,
        EventType [nvarchar](1024),
        Parameter [int],
        EventInfo [nvarchar](MAX)
    )

DECLARE @SPID INT, @ID INT, @CPU BIGINT, @IO BIGINT, @BLOCKED INT

select spid, blocked, SUM(cpu) as cpu, SUM(physical_io) as physical_io
INTO #SPID
from sys.sysprocesses
where  status<>'sleeping'
group by spid, blocked

DECLARE SPID CURSOR LOCAL
FOR 
SELECT SPID, BLOCKED, CPU, PHYSICAL_IO FROM #SPID
OPEN SPID
FETCH NEXT FROM SPID INTO @SPID, @BLOCKED, @CPU, @IO
WHILE @@FETCH_STATUS=0
BEGIN
    INSERT INTO @InputBuffer (EventType, Parameter, EventInfo) EXEC('DBCC INPUTBUFFER('+@SPID +')')
    SET @ID = SCOPE_IDENTITY()
    UPDATE @InputBuffer SET SPID = @SPID, BLOCKED=@BLOCKED, CPU = @CPU, PHYSICAL_IO = @IO WHERE ID = @ID
    FETCH NEXT FROM SPID INTO @SPID, @BLOCKED, @CPU, @IO
END
CLOSE SPID
DEALLOCATE SPID

UPDATE @InputBuffer SET EventInfo = REPLACE(EventInfo,'SET TRANSACTION ISOLATION LEVEL READ UNCOMMITTED','')
DELETE FROM @InputBuffer WHERE EventInfo='sys.sp_reset_connection;1' or EventInfo is null
SELECT * FROM @InputBuffer ORDER BY PHYSICAL_IO desc
Dave C
  • 7,272
  • 1
  • 19
  • 30
0

I'm not quite sure, but this could happen when the table is dead locked. check if that table in particular is deadlocked.

Oualid KTATA
  • 1,116
  • 10
  • 20
  • Is there any clever tools or something that could help do this? I've tried the old-fashioned way by inspecting code...! – noelicus Aug 13 '14 at 20:49
  • I'm not actually familiar with how SQL Server specifically does things, so I could be wrong, but how would that explain it working against one frontend and not another? His app failed, but another app interacting with the same database running the same command didn't. Assuming he re-initialized the database between runs, the behavior should have been identical. My gut tells me it's more of an ops configuration issue, or something on the client, than it is something in the database itself. – Parthian Shot Aug 13 '14 at 20:49
  • In SQL Server Management Studio, right-click the server node and select "Activity Monitor". Expand the "processes" pane, and wait for it to populate (this can take many seconds). You'll be able to see every process on the server, the database it's working in, its wait state, and what it is "blocked by". You can right-click any process and select "Details" to see what it's executing. – pmbAustin Aug 13 '14 at 22:52
  • You can use SQLProfiler and have traces on specific events. You can also use trace flags(http://msdn.microsoft.com/en-us/library/ms188396(v=sql.110).aspx). And here is another intersting link: http://technet.microsoft.com/en-us/library/ms178104(v=sql.105).aspx – Oualid KTATA Aug 21 '14 at 13:08