Exceptions when rolling back a transaction - connection already closed?

Question

Using Entity Framework 6.0.0, I'm seeing an exception when closing a transaction.

We'd been having problems with concurrent changes to the table, so I wrapped it in a transaction, and now I'm getting exceptions on rollback.

The code:

public LockInfo getSharedLock(string jobid)
{
    using (var myDbContext = new MyDbContext())
    {
        using (var transaction = myDbContext.Database.BeginTransaction())
        {
            try
            {
                this.logger.log("Attempting to get shared lock for {0}", jobid);

                var mylocks =
                    myDbContext.joblocks.Where(j => j.customerid == this.userContext.customerid)
                        .Where(j => j.jobid == jobid)
                        .Where(j => j.operatorid == this.userContext.operatorid);

                var exclusiveLock = mylocks.FirstOrDefault(
                    j => j.lockstatus == LockInfo.LockState.Exclusive);
                if (exclusiveLock != null)
                {
                    this.logger.log("{0} already had exclusive lock, ignoring", jobid);
                    return LockInfo.populate(exclusiveLock);
                }

                var sharedLock = mylocks.FirstOrDefault(
                    j => j.lockstatus == LockInfo.LockState.Shared);
                if (sharedLock != null)
                {
                    this.logger.log("{0} already had shared lock, ignoring", jobid));
                    sharedLock.lockdt = DateTime.Now;
                    myDbContext.SaveChanges();

                    return LockInfo.populate(sharedLock);
                }

                var joblock = new joblock
                {
                    customerid = this.userContext.customerid,
                    operatorid = this.userContext.operatorid,
                    jobid = jobid,
                    lockstatus = LockInfo.LockState.Shared,
                    sharedLock.lockdt = DateTime.Now
                };

                myDbContext.joblocks.Add(joblock);
                myDbContext.SaveChanges();
                transaction.Commit();

                this.logger.log("Obtained shared lock for {0}", jobid);
                return LockInfo.populate(joblock);
            }
            catch (Exception ex)
            {
                transaction.Rollback();
                this.logger.logException(ex, "Exception in getSharedLock(\"{0}\")", jobid);
                throw;
            }
        }
    }
}

You can see the logging, in the code above. We have logging enabled in the database, too. The log trace:

===================
NORMAL    TicketLockController.getLock("AK2015818002WL")
===================
SQL    Opened connection at 9/22/2015 2:47:49 PM -05:00
===================
SQL    Started transaction at 9/22/2015 2:47:49 PM -05:00
===================
NORMAL    Attempting to get shared lock for AK2015818002WL
===================
SQL    SELECT TOP (1) [Extent1].[customerid] AS [customerid]
    ,[Extent1].[jobid] AS [jobid]
    ,[Extent1].[lockdtdate] AS [lockdtdate]
    ,[Extent1].[lockdttime] AS [lockdttime]
    ,[Extent1].[operatorid] AS [operatorid]
    ,[Extent1].[lockstatus] AS [lockstatus]
    ,[Extent1].[changes] AS [changes]
FROM [dbo].[joblock] AS [Extent1]
WHERE ([Extent1].[customerid] = 'TESTTK')
    AND ([Extent1].[jobid] = 'AK2015818002WL')
    AND ([Extent1].[operatorid] = 'ADMIN')
    AND (N'Exclusive' = [Extent1].[lockstatus])
===================
SQL    SELECT TOP (1) [Extent1].[customerid] AS [customerid]
    ,[Extent1].[jobid] AS [jobid]
    ,[Extent1].[lockdtdate] AS [lockdtdate]
    ,[Extent1].[lockdttime] AS [lockdttime]
    ,[Extent1].[operatorid] AS [operatorid]
    ,[Extent1].[lockstatus] AS [lockstatus]
    ,[Extent1].[changes] AS [changes]
FROM [dbo].[joblock] AS [Extent1]
WHERE ([Extent1].[customerid] = 'TESTTK')
    AND ([Extent1].[jobid] = 'AK2015818002WL')
    AND ([Extent1].[operatorid] = 'ADMIN')
    AND (N'Shared' = [Extent1].[lockstatus])
===================
SQL    INSERT [dbo].[joblock] (
    [customerid]
    ,[jobid]
    ,[lockdtdate]
    ,[lockdttime]
    ,[operatorid]
    ,[lockstatus]
    ,[changes]
    )
VALUES (
    @0
    ,@1
    ,@2
    ,@3
    ,@4
    ,@5
    ,NULL
    )
===================
SQL    Closed connection at 9/22/2015 2:47:50 PM -05:00
===================
EXCEPTION    Unhandled exception caught: The underlying provider failed on Rollback.
===================
EXCEPTION    Inner Exception: Value cannot be null.
Parameter name: connection

The two selects are succeeding, then the insert is failing for some reason. throwing an exception, and for some reason the connection is closing before the Rollback() executes.

Any ideas what I'm doing wrong?

==== Adding stack traces ====

Stacktrace for the outer exception:

   at System.Data.Entity.Core.EntityClient.EntityTransaction.Rollback()
   at korterra.kt_api.Shared.TicketLockWrangler.getSharedLock(String jobid)
   at korterra.kt_ws.ApiControllers.Shared.TicketLockController.getSharedLock(TicketLockDTO ticketLockDTO)
   at lambda_method(Closure , Object , Object[] )
   at System.Web.Http.Controllers.ReflectedHttpActionDescriptor.ActionExecutor.<>c__DisplayClass10.<GetExecutor>b__9(Object instance, Object[] methodParameters)
   at System.Web.Http.Controllers.ReflectedHttpActionDescriptor.ActionExecutor.Execute(Object instance, Object[] arguments)
   at System.Web.Http.Controllers.ReflectedHttpActionDescriptor.ExecuteAsync(HttpControllerContext controllerContext, IDictionary`2 arguments, CancellationToken cancellationToken)
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Web.Http.Tracing.ITraceWriterExtensions.<TraceBeginEndAsyncCore>d__18`1.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Web.Http.Controllers.ApiControllerActionInvoker.<InvokeActionAsyncCore>d__0.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Web.Http.Tracing.ITraceWriterExtensions.<TraceBeginEndAsyncCore>d__18`1.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Web.Http.Controllers.ActionFilterResult.<ExecuteAsync>d__2.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Web.Http.Filters.AuthorizationFilterAttribute.<ExecuteAuthorizationFilterAsyncCore>d__2.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Web.Http.Controllers.ExceptionFilterResult.<ExecuteAsync>d__0.MoveNext()

Stacktrace for the inner exception:

   at System.Data.Entity.Utilities.Check.NotNull[T](T value, String parameterName)
   at System.Data.Entity.Infrastructure.Interception.DbTransactionInterceptionContext.WithConnection(DbConnection connection)
   at System.Data.Entity.Infrastructure.Interception.DbTransactionDispatcher.Rollback(DbTransaction transaction, DbInterceptionContext interceptionContext)
   at System.Data.Entity.Core.EntityClient.EntityTransaction.Rollback()

Answer 1

After the discussion, I started logging the exception before trying to roll back - and that revealed the error.

The transaction was deadlocked:

Exception in getSharedLock("ticketnumber123456"): An error occurred while updating the entries. See the inner exception for details.

Inner Exception: An error occurred while updating the entries. See the inner exception for details.

Inner Exception: Transaction (Process ID 139) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.

From what I'm reading, when your told a transaction has been made a deadlock victim, it's already been rolled back. Perhaps that is why we're getting an exception?

The fix seems to be either to recognize when we've deadlocked, and not rollback, or to not use transactions, and retry when we get a primary key violation.