Stored procedure called once, but executed twice.

Question

I'm using System.Data.SqlClient.SqlCommand.ExecuteNonQuery() to execute a stored procedure in SQL Server 2012.
From my application log, this execution has been called only once (it writes log for each calls), but, I realized the store procedure executed twice in database, and both execution were running in parallel which started at almost the same time (just few milliseconds different).
I know the execution time because the store procedure insert GETDATE() into a table and also update GETDATE() in another column of the table before it ends.

This happens very rarely. The store procedure is being called around 5 million times in a year and there are only 3 cases. This 3 cases are causing troubles.

Below is how my code looks like...

using (SqlConnection conn = new SqlConnection())
{
 conn.ConnectionString = "connectionstring";
 conn.Open();

 SqlCommand cmd = new SqlCommand();
 cmd.Connection = conn;
 cmd.CommandType = CommandType.StoredProcedure;
 cmd.CommandText = "a_stored_procedure";
 cmd.CommandTimeout = 60 * 60 * 2; //giving the execution running maximum 2 hours long
 cmd.Parameters.AddWithValue("@param1", 1);
 cmd.ExecuteNonQuery();
}
//write log here after the query execution

Anyone knows why is this happening?
The application is running in .Net 4.6.1.

Answer 1

Maybe it happened because of switching from summer time?

Answer 2

In addition to what other people have said: there is much to work from in your post.

I can tell you what did not happen: the piece of code you posted did not on its own account decide to run the procedure twice. That did simply not happen. So the cause is elsewhere. Since we don't know anything about your system, we can only speculate. For all I care, it could be as simple as that were two instances of your application running at the same time.

You have a command timeout of two hours, which makes me think that it is a long-running procedure, and in such case the milliseconds will not matter. But if there can also be very short executions, they can. It is perfectly possible for time to go backwards in a modern computer, so that getdate() at point B returns an earlier value than at point A, although A was before B in real-world time. (I believe this is due to that the time may be gotten from different CPUs. Balanced power plans may also have to do with it.) Thus, you cannot trust timestamps on that granularity fully. But if all executions are several seconds this is not the issue.

By the way, I think that for recording timestamps, the best data type is datetime2(3) and use the function sysdatetime() which has an accuracy of 1 ms. Although, that does of course not happen when time goes backwards.

Answer 3

hello @Viorel , try SqlTransaction in your script --

https://learn.microsoft.com/en-us/dotnet/api/system.data.sqlclient.sqltransaction?view=dotnet-plat-ext-5.0

Answer 4

The code you posted does not run it twice.

It is much more likely it was already running when it was started again, probably due to being blocked or a client failure or something.