System.Data.Entity.Infrastructure.CommitFailedException: C# Multithreading & SQL Server 2012

Question

We have a C# multi threaded (100 threads) program which reads the records from the DB and each thread picks up one record (one Entity Framework connection per thread) and update the a single DB table.

For first few minutes (5 minutes) the program works fine without exception then all of a sudden all threads starts throwing the below error messages.. After ~1 min everything will come back to normal stage.. I think the SQL Server is getting too many locks for a single DB table (might be trying to acquire table lock on that table) or too many connections to a single DB and closing all the connections..

I am unable to debug this, can some one help me in getting the following information,

1. Where does SQL Server 2012 store its logs?

2. Can we increase the log level to see why it throws an exception while saving the DB entity

3. How to get the number of locks per a table, different kind of locks (table lock, page lock, num row locks, etc) acquired by DB

Any other pointers to debug this issue.

FYI, I didn't find anything useful in sqlerror log got from this cmd:

SELECT SERVERPROPERTY('ErrorLogFileName')

Here is the stack trace of the exception:

System.Data.Entity.Infrastructure.CommitFailedException: An error was reported while committing a database transaction but it could not be determined whether the transaction succeeded or failed on the database server. See the inner exception and http://go.microsoft.com/fwlink/?LinkId=313468 for more information.

System.Data.SqlClient.SqlException: Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding.
System.ComponentModel.Win32Exception: The wait operation timed out
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.TdsParserStateObject.ReadSniError(TdsParserStateObject stateObj, UInt32 error)
  at System.Data.SqlClient.TdsParserStateObject.ReadSniSyncOverAsync()
  at System.Data.SqlClient.TdsParserStateObject.TryReadNetworkPacket()
  at System.Data.SqlClient.TdsParserStateObject.TryPrepareBuffer()
  at System.Data.SqlClient.TdsParserStateObject.TryReadByte(Byte& value)
  at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
  at System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj)
  at System.Data.SqlClient.TdsParser.TdsExecuteTransactionManagerRequest(Byte[] buffer, TransactionManagerRequestType request, String transactionName, TransactionManagerIsolationLevel isoLevel, Int32 timeout, SqlInternalTransaction transaction, TdsParserStateObject stateObj, Boolean isDelegateControlRequest)
  at System.Data.SqlClient.SqlInternalConnectionTds.ExecuteTransactionYukon(TransactionRequest transactionRequest, String transactionName, IsolationLevel iso, SqlInternalTransaction internalTransaction, Boolean isDelegateControlRequest)
  at System.Data.SqlClient.SqlInternalConnectionTds.ExecuteTransaction(TransactionRequest transactionRequest, String name, IsolationLevel iso, SqlInternalTransaction internalTransaction, Boolean isDelegateControlRequest)
  at System.Data.SqlClient.SqlInternalTransaction.Commit()
  at System.Data.SqlClient.SqlTransaction.Commit()
  at System.Data.Entity.Infrastructure.Interception.DbTransactionDispatcher.<Commit>b__c(DbTransaction t, DbTransactionInterceptionContext c)
  at System.Data.Entity.Infrastructure.Interception.InternalDispatcher1.Dispatch[TTarget,TInterceptionContext](TTarget target, Action2 operation, TInterceptionContext interceptionContext, Action3 executing, Action`3 executed)
--- End of inner exception stack trace ---
at System.Data.Entity.Infrastructure.Interception.InternalDispatcher1.Dispatch[TTarget,TInterceptionContext](TTarget target, Action2 operation, TInterceptionContext interceptionContext, Action3 executing, Action3 executed)
at System.Data.Entity.Infrastructure.Interception.DbTransactionDispatcher.Commit(DbTransaction transaction, DbInterceptionContext interceptionContext)
at System.Data.Entity.Core.EntityClient.EntityTransaction.Commit()
at System.Data.Entity.Core.Objects.ObjectContext.ExecuteInTransaction[T](Func1 func, IDbExecutionStrategy executionStrategy, Boolean startLocalTransaction, Boolean releaseConnectionOnSuccess)
  at System.Data.Entity.Core.Objects.ObjectContext.SaveChangesToStore(SaveOptions options, IDbExecutionStrategy executionStrategy, Boolean startLocalTransaction)
  at System.Data.Entity.Core.Objects.ObjectContext.<>c__DisplayClass2a.<SaveChangesInternal>b__27()
  at System.Data.Entity.SqlServer.DefaultSqlExecutionStrategy.Execute[TResult](Func1 operation)
at System.Data.Entity.Core.Objects.ObjectContext.SaveChangesInternal(SaveOptions options, Boolean executeInExistingTransaction)
at System.Data.Entity.Core.Objects.ObjectContext.SaveChanges(SaveOptions options)
at System.Data.Entity.Internal.InternalContext.SaveChanges()
at System.Data.Entity.Internal.LazyInternalContext.SaveChanges()
at System.Data.Entity.DbContext.SaveChanges()

Answer 1

Looks like blocking in action.

You should try to monitor blocking with tools such as sp_WhoIsActive or an Extended Events session.

If you want to use Extended Events, there's a tool called ExtendedTSQLCollector that can help you automate monitoring and collection of the events you need. I wrote a blog post on how to use it to monitor blocking and deadlocking. You can find it here: Monitoring blocking and deadlocking with Extended T-SQL Collector