In my application I have a simple insert, when captured with profiler it looks like this
insert into ford.tblFordCompoundFlowVehicle
(FordCompoundFlowID, CompoundVehicleID, SortOrder, Status1ToSend, Status2ToSend, FordFlowTriggerID, SendTriggerSatisfied, DateSend, FordCompoundFlowDefinitionID)
select fcfd.FordCompoundFlowID,
9711,
fcfdd.SortOrder,
fcfdd.Status1ToSend,
fcfdd.Status2ToSend,
fcfdd.FordFlowTriggerID,
0,
null,
2
from ford.tblFordCompoundFlowDefinitionDetail fcfdd
inner join ford.tblFordCompoundFlowDefinition fcfd on fcfdd.FordCompoundFlowDefinitionID = fcfd.FordCompoundFlowDefinitionID
where fcfdd.FordCompoundFlowDefinitionID = 2
order by fcfdd.SortOrder
This is sent to the database using Dapper like this
string sql =
$"""
insert into ford.tblFordCompoundFlowVehicle
(FordCompoundFlowID, CompoundVehicleID, SortOrder, Status1ToSend, Status2ToSend, FordFlowTriggerID, SendTriggerSatisfied, DateSend, FordCompoundFlowDefinitionID)
select fcfd.FordCompoundFlowID,
{compoundVehicleID},
fcfdd.SortOrder,
fcfdd.Status1ToSend,
fcfdd.Status2ToSend,
fcfdd.FordFlowTriggerID,
0,
null,
{fordCompoundFlowDefinitionID}
from ford.tblFordCompoundFlowDefinitionDetail fcfdd
inner join ford.tblFordCompoundFlowDefinition fcfd on fcfdd.FordCompoundFlowDefinitionID = fcfd.FordCompoundFlowDefinitionID
where fcfdd.FordCompoundFlowDefinitionID = {fordCompoundFlowDefinitionID.Value}
order by fcfdd.SortOrder
OPTION(RECOMPILE)
""";
connection.Execute(sql, null, transaction);
I did not use an SqlCommand to keep this code a bit shorter, also the values are all int so SQL injection would be difficult anyway.
Now for the problem, when this query runs it takes so long it times out, but when I capture the query in profiler and run it in SSMS it is very fast.
I also tried the option OPTION(RECOMPILE) in the application, but it does not help
Execution Plans:
So I got the execution plan from SSMS
and captured the slow application plan from Activity monitor
I do not have the knowledge myself to compare these plans and see the problem, so I am hoping someone here can compare them and help me point out the problem.
The transaction is done like this
using (SqlConnection connection = new SqlConnection(ConnectionString))
{
connection.Open();
using (SqlTransaction transaction = connection.BeginTransaction())
{
try
{
fordCompoundFlowDefinitionID = CreateFordCompoundFlowVehicle(connection, transaction, compoundVehicleID);
transaction.Commit();
}
catch (Exception ex)
{
transaction.Rollback();
throw;
}
}
}
private int? CreateFordCompoundFlowVehicle(SqlConnection connection, SqlTransaction transaction, int compoundVehicleID)
{
int? result = null;
// check if there is any importdata for this compoundvehicleid, if not than it stops right here
int? fordCompoundFlowDefinitionID = GetFordCompoundFlowDefinitionID(connection, transaction, compoundVehicleID);
if (fordCompoundFlowDefinitionID.HasValue)
{
string sql =
$"""
insert into ford.tblFordCompoundFlowVehicle
(FordCompoundFlowID, CompoundVehicleID, SortOrder, Status1ToSend, Status2ToSend, FordFlowTriggerID, SendTriggerSatisfied, DateSend, FordCompoundFlowDefinitionID)
select fcfd.FordCompoundFlowID,
{compoundVehicleID},
fcfdd.SortOrder,
fcfdd.Status1ToSend,
fcfdd.Status2ToSend,
fcfdd.FordFlowTriggerID,
0,
null,
{fordCompoundFlowDefinitionID}
from ford.tblFordCompoundFlowDefinitionDetail fcfdd
inner join ford.tblFordCompoundFlowDefinition fcfd on fcfdd.FordCompoundFlowDefinitionID = fcfd.FordCompoundFlowDefinitionID
where fcfdd.FordCompoundFlowDefinitionID = {fordCompoundFlowDefinitionID.Value}
order by fcfdd.SortOrder
OPTION(RECOMPILE)
""";
-- THIS TIMES OUT
connection.Execute(sql, null, transaction);
result = fordCompoundFlowDefinitionID;
}
return result;
}
I altered the code to a parametrized query as suggested, but get the same result
string sql =
"""
insert into ford.tblFordCompoundFlowVehicle
(FordCompoundFlowID, CompoundVehicleID, SortOrder, Status1ToSend, Status2ToSend, FordFlowTriggerID, SendTriggerSatisfied, DateSend, FordCompoundFlowDefinitionID)
select fcfd.FordCompoundFlowID,
@CompoundVehicleID,
fcfdd.SortOrder,
fcfdd.Status1ToSend,
fcfdd.Status2ToSend,
fcfdd.FordFlowTriggerID,
0,
null,
@FordCompoundFlowDefinitionID
from ford.tblFordCompoundFlowDefinitionDetail fcfdd
inner join ford.tblFordCompoundFlowDefinition fcfd on fcfdd.FordCompoundFlowDefinitionID = fcfd.FordCompoundFlowDefinitionID
where fcfdd.FordCompoundFlowDefinitionID = @FordCompoundFlowDefinitionID
order by fcfdd.SortOrder
OPTION(RECOMPILE)
""";
var parameters = new {CompoundVehicleID = compoundVehicleID, FordCompoundFlowDefinitionID = fordCompoundFlowDefinitionID };
connection.Execute(sql, parameters, transaction);
The captured statement in profiler
exec sp_executesql N'insert into ford.tblFordCompoundFlowVehicle
(FordCompoundFlowID, CompoundVehicleID, SortOrder, Status1ToSend, Status2ToSend, FordFlowTriggerID, SendTriggerSatisfied, DateSend, FordCompoundFlowDefinitionID)
select fcfd.FordCompoundFlowID,
@CompoundVehicleID,
fcfdd.SortOrder,
fcfdd.Status1ToSend,
fcfdd.Status2ToSend,
fcfdd.FordFlowTriggerID,
0,
null,
@FordCompoundFlowDefinitionID
from ford.tblFordCompoundFlowDefinitionDetail fcfdd
inner join ford.tblFordCompoundFlowDefinition fcfd on fcfdd.FordCompoundFlowDefinitionID = fcfd.FordCompoundFlowDefinitionID
where fcfdd.FordCompoundFlowDefinitionID = @FordCompoundFlowDefinitionID
order by fcfdd.SortOrder
OPTION(RECOMPILE)',N'@CompoundVehicleID int,@FordCompoundFlowDefinitionID int',@CompoundVehicleID=9711,@FordCompoundFlowDefinitionID=2
go
System.Data.SqlClient.SqlException HResult=0x80131904
Message=Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding. Operation cancelled by user. Source=Core .Net SqlClient Data Provider
StackTrace: at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action1 wrapCloseInAction) at System.Data.SqlClient.SqlInternalConnection.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, TaskCompletionSource1 completion, Int32 timeout, Task& task, Boolean asyncWrite, String method) at System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(TaskCompletionSource1 completion, Boolean sendToPipe, Int32 timeout, Boolean asyncWrite, String methodName) at System.Data.SqlClient.SqlCommand.ExecuteNonQuery() at Dapper.SqlMapper.ExecuteCommand(IDbConnection cnn, CommandDefinition& command, Action2 paramReader) in /_/Dapper/SqlMapper.cs:line 2965 at Dapper.SqlMapper.ExecuteImpl(IDbConnection cnn, CommandDefinition& command) in /_/Dapper/SqlMapper.cs:line 656 at Dapper.SqlMapper.Execute(IDbConnection cnn, String sql, Object param, IDbTransaction transaction, Nullable1 commandTimeout, Nullable1 commandType) in /_/Dapper/SqlMapper.cs:line 527 at WebServiceMobile.Repositories.Compound.RepositoryFordFlow.CreateFordCompoundFlowVehicle(SqlConnection connection, SqlTransaction transaction, Int32 compoundVehicleID) in C:\Development\Git\WebServices\WebServiceMobile\Repositories\Compound\Ford\RepositoryFordFlow.cs:line 124 at WebServiceMobile.Repositories.Compound.RepositoryFordFlow.HandleIncomingVehicle(Int32 compoundVehicleID, Nullable1 dateInActual) in C:\Development\Git\WebServices\WebServiceMobile\Repositories\Compound\Ford\RepositoryFordFlow.cs:line 29Inner Exception 1: Win32Exception: The wait operation timed out.
I tried without using a transaction, same result
System.Data.SqlClient.SqlException: 'Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding. Operation cancelled by user.'
New plan captured from the query running in the application
plan:
https://www.brentozar.com/pastetheplan/?id=B1vTWaMIR
live statistics:
https://www.brentozar.com/pastetheplan/?id=H1-8MpGUA
Running sp_who2
As suggested I ran exec sp_who2 while the slow query is running, this is the result
| SPID | Status | Login | HostName | BlkBy | DBName | Command | CPUTime | DiskIO | LastBatch | ProgramName | SPID | REQUESTID |
|---|---|---|---|---|---|---|---|---|---|---|---|---|
| 87 | SUSPENDED | PalmTest | XXXX | 77 | xxxx | INSERT | 0 | 2 | 06/21 11:46:38 | gttWebService | 87 | 0 |
I have found the problem, it seems when run from the application there was a lock that puts my query in suspended state.
I discovered this thanks to a comment of @sa-es-ir that made me run sp_who2 while the slow query was running. Then I noticed a block from the same application I was running my query from, but with another spid.
So the query had actually not much to do with the problem and the execution plans should be quit similar I guess, but since the query kept waiting the client got tired of waiting and called a timeout.
How did this occur?
It seems that when your connection in C# begins a transaction, and you create a new connection that begins a new transaction, then any query that needs a row that was inserted/updated in the first transaction needs to wait until that transaction ended.
Basically I had something like this
using (SqlConnection connection = new SqlConnection(ConnectionString))
{
connection.Open();
using (SqlTransaction transaction = connection.BeginTransaction())
{
try
{
SomeProcedure();
transaction.Commit();
}
catch (Exception ex)
{
transaction.Rollback();
throw;
}
}
}
public void SomeProcedure()
{
using (SqlConnection connection = new SqlConnection(ConnectionString))
{
connection.Open();
using (SqlTransaction transaction = connection.BeginTransaction())
{
try
{
// HERE WAS MY QUERY THAT TIMED OUT
transaction.Commit();
}
catch (Exception ex)
{
transaction.Rollback();
throw;
}
}
}
}
I now altered my method so it checks if it is in an existing connection/transaction and then uses that and only create a new one if that is not the case.