I have an insert statement generated by the .NET Entity Framework. In most cases, this particular insert will execute in 0ms according SQL Server Profiler.
One out of every 30 or so inserts will jump to as high as 12 seconds duration, causing the .NET client on the other end to show as "Not Responding" while it waits. Server load should not be an issue as our server is very, very lightly loaded.
Here is the table the insert is being performed against:
SET ANSI_NULLS ON
GO
SET QUOTED_IDENTIFIER ON
GO
SET ANSI_PADDING ON
GO
CREATE TABLE [dbo].[ProductEvents](
[EventID] [int] IDENTITY(1,1) NOT NULL,
[KID] [int] NOT NULL,
[EventDescription] [varchar](50) NOT NULL,
[EventDate] [datetime] NOT NULL,
[UserName] [varchar](50) NOT NULL,
[Notes] [varchar](max) NOT NULL,
[Version] [timestamp] NOT NULL,
[IsSynchronized] [bit] NOT NULL,
[LastSyncDate] [datetime] NULL,
CONSTRAINT [PK_ProductEvents] PRIMARY KEY CLUSTERED
([EventID] ASC ) WITH (PAD_INDEX = OFF, STATISTICS_NORECOMPUTE = OFF,
IGNORE_DUP_KEY = OFF,ALLOW_ROW_LOCKS = ON, ALLOW_PAGE_LOCKS = ON) ON [PRIMARY]
) ON [PRIMARY] TEXTIMAGE_ON [PRIMARY]
GO
SET ANSI_PADDING OFF
GO
ALTER TABLE [dbo].[ProductEvents] ADD CONSTRAINT [DF_ProductEvents_IsSychronized]
DEFAULT ((0)) FOR [IsSynchronized]
GO
ALTER TABLE [dbo].[ProductEvents] WITH CHECK ADD CONSTRAINT
[FK_ProductEvents_Products] FOREIGN KEY([KID])
REFERENCES [dbo].[Products] ([KID])
ON DELETE CASCADE
GO
ALTER TABLE [dbo].[ProductEvents] CHECK CONSTRAINT [FK_ProductEvents_Products]
GO
And the query as seen by SQL Server Profiler (actual example):
exec sp_executesql N'insert [dbo].[ProductEvents]([KID], [EventDescription],
[EventDate], [UserName], [Notes], [IsSynchronized], [LastSyncDate])
values (@0, @1, @2, @3, @4, @5, null)
select [EventID], [Version]
from [dbo].[ProductEvents]
where @@ROWCOUNT > 0 and [EventID] = scope_identity()',N'@0 int,@1 varchar(50),@2
datetime2(7),@3 varchar(50),@4 varchar(max) ,@5
bit',@0=1894,@1='Modified',@2='2013-08-12
08:09:25.4766233',@3='KNEXTION\aellison',
@4='Description changed from Mini Awareness Ribbon Cookie Cutter - RM 1698 to Mini
Awareness Ribbon Cookie Cutter - R&M 1698.',@5=0
Here is the execution plan as a screenshot from SSMS:
Any ideas on how to begin to track this down?
The actual and estimated plans seem to be the same.
It is a multi-user application, and this table would be one of the more active tables.
Is there any easy way in the Profiler or any other tool to see if blocking is the issue? Are there any other issues I should be looking for besides blocking?
Best Answer
Could be other sessions are causing blocking. See the Q& A http://dba.stackexchange.com/questions/34313/identify-blocking-and-send-alert.
If the actual and estimated plans are the same, there's no point providing them, because they can't explain anything (aside from general inefficiencies that should apply to all executions, not just the slow instances). You'll could monitor
sys.dm_exec_requests
when it is running slowly to see who/what it's waiting on.You can also monitor wait statistics (it could be severely bottlenecked I/O, for example). Reproducing in Plan Explorer might help here, as you can automatically get the wait statistics for your session (unless you fire up your own extended events session, you can only get system-wide waits on your own).
To capture what is going on during the potential blocking periods, you could also use Service Broker and Event Notifications. Tony Rogerson back in 2007 posted a sample that reports on 10 second (or longer) blocks that you could use.
Also check auto-growth events and settings for the database and log. Occasional long delays can be caused by having to wait for a data or log file to grow.