2

I'm having intermediate timeouts when calling this stored procedure from ASP.NET frontend environment on a production site. it returns the following sql exception:

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

Funny thing is, when executing this procedure on the server, or from a remote pc using Management Studio, it executes in 6s. But yet, sometimes times out from when executed from the ASP.NET application? Can this query be improved? Or is this issue related to something else? Anyone who can help? I;ve read some threads about increasing the timeout and enabling pooling on the connectionstring in my web.config, but haven't tried that yet.

 ALTER PROCEDURE [dbo].[Report_Activity]
    (
        @StartDate      DATETIME
    ,   @EndDate        DATETIME
    ,   @TotalActions INT OUTPUT
    )

    AS
    BEGIN 

        SELECT      @TotalActions = COUNT(EventHistoryId)
        FROM        dbo.SessionEventHistory
        WHERE       DateCreated BETWEEN @StartDate AND @EndDate

        SELECT      EventDescription, COUNT(EventHistoryId) AS EventCount           
        FROM        dbo.SessionEventHistory
        WHERE       DateCreated BETWEEN @StartDate AND @EndDate
        GROUP BY    EventDescription
        ORDER BY    EventDescription

SQL SCHEMAS:

CREATE TABLE [dbo].[SessionEventHistory](
    [EventHistoryID] [int] IDENTITY(1,1) NOT NULL,
    [SessionHistoryID] [int] NOT NULL,
    [CategoryID] [int] NULL,
    [UserName] [nvarchar](50) NULL,
    [IPAddress] [nvarchar](20) NOT NULL,
    [EventDescription] [nvarchar](1000) NOT NULL,
    [EventData] [varbinary](max) NULL,
    [DateCreated] [datetime] NOT NULL,
 CONSTRAINT [PK_UserEventHistory] PRIMARY KEY CLUSTERED 
(
    [EventHistoryID] ASC
)WITH (PAD_INDEX  = OFF, STATISTICS_NORECOMPUTE  = OFF, IGNORE_DUP_KEY = OFF, ALLOW_ROW_LOCKS  = ON, ALLOW_PAGE_LOCKS  = ON) ON [PRIMARY]
) ON [PRIMARY]

GO

ALTER TABLE [dbo].[SessionEventHistory] ADD  CONSTRAINT [DF_UserEventHistory_DateCreated]  DEFAULT (getdate()) FOR [DateCreated]
GO

Table has 3 indexes:

/****** Object:  Index [IX_SessionEventHistory_SessionHistoryId_CategoryId]    Script Date: 07/04/2012 10:47:06 ******/
CREATE NONCLUSTERED INDEX [IX_SessionEventHistory_SessionHistoryId_CategoryId] ON [dbo].[SessionEventHistory] 
(
    [SessionHistoryID] ASC,
    [CategoryID] ASC
)WITH (PAD_INDEX  = OFF, STATISTICS_NORECOMPUTE  = OFF, SORT_IN_TEMPDB = OFF, IGNORE_DUP_KEY = OFF, DROP_EXISTING = OFF, ONLINE = OFF, ALLOW_ROW_LOCKS  = ON, ALLOW_PAGE_LOCKS  = ON) ON [PRIMARY]
GO


/****** Object:  Index [IX_SessionEventHistory_UserName_DateCreated]    Script Date: 07/04/2012 10:47:09 ******/
CREATE NONCLUSTERED INDEX [IX_SessionEventHistory_UserName_DateCreated] ON [dbo].[SessionEventHistory] 
(
    [UserName] ASC,
    [DateCreated] ASC
)WITH (PAD_INDEX  = OFF, STATISTICS_NORECOMPUTE  = OFF, SORT_IN_TEMPDB = OFF, IGNORE_DUP_KEY = OFF, DROP_EXISTING = OFF, ONLINE = OFF, ALLOW_ROW_LOCKS  = ON, ALLOW_PAGE_LOCKS  = ON) ON [PRIMARY]
GO


/****** Object:  Index [PK_UserEventHistory]    Script Date: 07/04/2012 10:47:14 ******/
ALTER TABLE [dbo].[SessionEventHistory] ADD  CONSTRAINT [PK_UserEventHistory] PRIMARY KEY CLUSTERED 
(
    [EventHistoryID] ASC
)WITH (PAD_INDEX  = OFF, STATISTICS_NORECOMPUTE  = OFF, SORT_IN_TEMPDB = OFF, IGNORE_DUP_KEY = OFF, ONLINE = OFF, ALLOW_ROW_LOCKS  = ON, ALLOW_PAGE_LOCKS  = ON) ON [PRIMARY]
GO

EDIT

I added the following Index, does it look okay?

CREATE NONCLUSTERED INDEX [IX_SessionEventHistory_DateCreated] ON [dbo].[SessionEventHistory] 
(
    [DateCreated] ASC
)WITH (PAD_INDEX  = OFF, STATISTICS_NORECOMPUTE  = OFF, SORT_IN_TEMPDB = OFF, IGNORE_DUP_KEY = OFF, DROP_EXISTING = OFF, ONLINE = OFF, ALLOW_ROW_LOCKS  = ON, ALLOW_PAGE_LOCKS  = ON) ON [PRIMARY]
GO

enter image description here

Aaron Bertrand
  • 272,866
  • 37
  • 466
  • 490
FaNIX
  • 1,888
  • 6
  • 33
  • 60
  • 2
    Putting an index on [DateCreated] would probably help – DJ. Jul 04 '12 at 01:10
  • @DJ I agree, that index will probably help overall efficiency, but if the same query with the same parameters behaves differently from different applications, there's probably more to it than that. – Aaron Bertrand Jul 04 '12 at 01:12
  • There is already an index on DateCreated (IX_SessionEventHistory_UserName_DateCreated) ? – FaNIX Jul 04 '12 at 01:47
  • @FaNIX but that index doesn't have `DateCreated` as a leading column. So unless the query also includes a where clause or group by involving the `UserName` column, you should see in the execution plan that this index is not used to help satisfy this query. – Aaron Bertrand Jul 04 '12 at 02:16
  • Could be parameter sniffing - try using local date vars - also review the excellent links that Aaron has posted below... – DJ. Jul 04 '12 at 02:23
  • I added the code for the new index above. – FaNIX Jul 04 '12 at 02:43
  • 6 seconds is a pretty long query. Look at the query plan. It may recommend a new index. Since you group by EventDescription it is a prime candidate for an index. And are the indexes fragmented? – paparazzo Jul 04 '12 at 03:17
  • Sorry guys, Im no SQL optimization guru, so this is all new to me. I attached the execution plan. It recommends adding an index to DateCreated, which I already did, but it still display that message? – FaNIX Jul 04 '12 at 03:30

2 Answers2

4

Take a look at sys.dm_exec_sessions for your ASP.Net application and for your SSMS session. I will hazard a guess that at least one of your SET settings is different. This can contribute to different plans (ultimately this gets attributed to parameter sniffing) and the app side usually ends up worse off for it.

See these other questions for a lot more details:

Stored procedure slow when called from web, fast from Management Studio

Procedure times out from ADO.NET but not in SSMS

Query times out when executed from web, but super-fast when executed from SSMS

ADO .NET vs. SQL Server Management Studio - ADO performs worse

Also please read this great article by Erland Sommarskog.

Community
  • 1
  • 1
Aaron Bertrand
  • 272,866
  • 37
  • 466
  • 490
  • Problem wasn't with the query, although it could be optimized a little bit. Issue was with SQLDBCommand.CommandTimeout. By default it's 30seconds, my procedure didn't have the WITH (NOLOCK), so when multiple users request the report, it slows down considerably, then goes over 30s, and boom, the DBCommand closes with SqlTimeout exception. By increasing .CommandTimeout=90, and introducing the WITH (NOLOCK), solved the problem :) – FaNIX Jul 04 '12 at 04:12
  • 1
    Well I wouldn't really call either of those things a fix, but glad you threw a bandaid on it. :-) – Aaron Bertrand Jul 04 '12 at 04:13
0

Maybe it's a poor execution plan created with some atypical SP call. Try using WITH RECOMPILE either when you execute the SP or in the definition.

EXEC [dbo].[Report_Activity] @StartDate, @EndDate, @TotalActions WITH RECOMPILE

or

ALTER PROCEDURE [dbo].[Report_Activity]
    (
        @StartDate      DATETIME
    ,   @EndDate        DATETIME
    ,   @TotalActions INT OUTPUT
    )
WITH RECOMPILE
AS
...

You can also run sp_recompile to mark your SP for recompilation next time it is executed.

dan radu
  • 2,772
  • 4
  • 18
  • 23