单项数据表触发死锁

Question

我们有一个 webapi，它处理大量请求，有时每秒处理大量请求，并且在每个请求开始时，我们使用 Entity 框架向我们的日志表发送一个日志条目。

但是，我们日志表的这个条目通常会在另一个进程上死锁，我不明白是什么原因造成的。

using (UnitOfWork unitofwork = new UnitOfWork())
{
    unitofwork.WebApiRequestLogRepository.Insert(new WebApiRequestLog
    {
        Created = DateTime.Now,
        Username = System.Threading.Thread.CurrentPrincipal.Identity.Name,
        Controller = actionContext.ActionDescriptor.ControllerDescriptor.ControllerName,
        Method = actionContext.ActionDescriptor.ActionName,
        MethodParameters = xml,
        ApplicationVersion = AppSettings.Instance.Version,
        Url = HttpContext.Current.Request.Url.ToString(),
    });
    unitofwork.Save();
}

unitofwork 是对单个上下文的封装，可以同时进行多项更改。保存调用 context.SaveChanges

实体框架生成的SQL代码

INSERT [log].[WebApiRequestLog]([Created], [Username], [Controller], [Method], [ApplicationVersion], [Url], [MethodParameters])
VALUES (@0, @1, @2, @3, @4, @5, @6)
SELECT [Id]
FROM [log].[WebApiRequestLog]
WHERE @@ROWCOUNT > 0 AND [Id] = scope_identity()

谁能解释一下为什么单次插入日志表会导致死锁？

编辑

public virtual void Insert(TEntity entity)
{
    DbSet.Add(entity);
}

public void Save()
    {
        StringBuilder builder = new StringBuilder();
        try
        {
            _context.Database.Log = s => builder.AppendLine(s);
            _context.SaveChanges();
        }
        catch (DbEntityValidationException e)
        {
            HandleDbEntityValidationException(e);
        }
        catch (Exception e)
        {
            Exception ex = new Exception(builder.ToString(), e);
            throw ex;
        }
    }

Answer 1

我提出了一些有用的查询，您可以在死锁期间运行这些查询以显示当前的等待情况。它们可以帮助您识别出现死锁的情况。

此外，您可能希望在出现问题时查找如何将save deadlock graphs 发送到数据库。如果您在Database Administrator Exchange 上发布了一个死锁图，我相信您会找到更多关于什么是锁定的信息。

1. 确保您没有中断 TransactionScope 或 其他开发人员正坐在 TransactionScope 代码块内的断点上。

2. 如果您的数据库非常繁忙并且您不担心脏，那么您可以使用以下提示减少读取锁定。

   CREATE PROCEDURE SaveWebApiRequestLog(...)
   AS BEGIN
       SET TRANSACTION ISOLATION LEVEL READ UNCOMMITTED 
       INSERT log.WebApiRequestLog(Created,Username,Controller,Method,ApplicationVersion,Url,MethodParameters)
       VALUES(...)
       SELECT Id FROM log.WebApiRequestLog
       WHERE Id = @@IDENTITY
   END
   

   或

   INSERT [log].[WebApiRequestLog]([Created], [Username], [Controller], [Method], [ApplicationVersion], [Url], [MethodParameters])
   VALUES (@0, @1, @2, @3, @4, @5, @6)
   SELECT [Id]
   FROM [log].[WebApiRequestLog] WITH NOLOCK
   WHERE @@ROWCOUNT > 0 AND [Id] = scope_identity()
   

显示等待

--kill 65
SELECT 
    S.Text, R.Session_id,R.Status,R.Command,R.CPU_Time,R.Total_Elapsed_Time
FROM    
    sys.dm_exec_requests R
    CROSS APPLY sys.dm_exec_sql_text(sql_handle) AS S 

--EXEC sp_who2
SELECT  W.session_id,ot.task_state,W.wait_type, W.wait_duration_ms, W.blocking_session_id, W.resource_description, S.host_name, S.program_name
FROM  
    sys.dm_os_waiting_tasks  W  
    INNER  JOIN sys.dm_os_tasks ot ON ot.task_address = W.waiting_task_address 
    INNER JOIN sys.dm_exec_sessions S ON S.session_id = W.session_id 
WHERE 
    S.is_user_process =  1

SELECT 
    SessionID = es.session_id,
    Login =es.original_login_name,
    Host = es.host_name,
    RequestStart=es.last_request_start_time,
    RequerstEnd=es.last_request_end_time,
    Status =es.status,
    BockedBy =er.blocking_session_id,
    WaitType =er.wait_type, 
    WaitTime = er.wait_time,
    LastWaitType = er.last_wait_type,
    WaitResource = er.wait_resource,
    DatabaseID = DB_NAME(er.database_id),
    Command = er.command,
    --,sql_text=st.text
    TransactionIsolation =
        CASE es.transaction_isolation_level
            WHEN 0 THEN 'Unspecified'
            WHEN 1 THEN 'Read Uncommitted'
            WHEN 2 THEN 'Read Committed'
            WHEN 3 THEN 'Repeatable'
            WHEN 4 THEN 'Serializable'
            WHEN 5 THEN 'Snapshot'
        END,
    CPUTime = COALESCE(es.cpu_time,0) + COALESCE(er.cpu_time,0),
    IOTime = COALESCE(es.reads,0) + COALESCE(es.writes,0) + COALESCE(er.reads,0) + COALESCE(er.writes,0),
    TransactioCount = COALESCE(er.open_transaction_count,-1),
    ProgramName = COALESCE(es.program_name,''),
    LoginTme = es.login_time
FROM 
    sys.dm_exec_sessions es
    LEFT OUTER JOIN sys.dm_exec_connections ec ON es.session_id = ec.session_id
    LEFT OUTER JOIN sys.dm_exec_requests er ON es.session_id = er.session_id
    LEFT OUTER JOIN sys.server_principals sp ON es.security_id = sp.sid
    LEFT OUTER JOIN sys.dm_os_tasks ota ON es.session_id = ota.session_id
    LEFT OUTER JOIN sys.dm_os_threads oth ON ota.worker_address = oth.worker_address
    CROSS APPLY sys.dm_exec_sql_text(er.sql_handle) AS st
WHERE 
    es.is_user_process = 1 
    and 
    es.session_id <> @@spid
ORDER BY
     es.session_id