搞搞就懂

前言

---

當系統須提供使用者操作行為的統計數據時，可能需要建立一支 Web API 來紀錄各用戶點擊功能的相關資訊，而這種 Web API 的使用率其實還滿高，BUT 真的不是那麼重要 (即使發生錯誤也不必告知用戶，且執行失敗也不會造成系統顯著傷害)，所以針對此種情境就可以考慮套用非同步射後不理機制，節省 Web API 被占用的時間，把資源留給其他更重要的項目！

 

系統現狀 - 同步執行

---

目前系統在紀錄點擊次數的方式是透過一個同步執行的 Web API  進行記錄，也就是需完整處理完 LOG 寫入動作後才會回應呼叫端；簡單建立一下測試情境，模擬 LOG 寫入時間花費 1 秒，因此模擬寫入 LOG 的 Stored Procedure 大致如下。

CREATE PROCEDURE [dbo].[usp_write_log_no_return]
@Message NVarChar(Max)
AS
BEGIN

	SET NOCOUNT ON;

	-- delay 1 second
	WAITFOR DELAY '00:00:01';

	-- write log
	INSERT INTO [dbo].[LogHistory]
		([Message] ,[LogDateTime])
	VALUES
		(@Message , GETDATE() );

END

接著在 LogController 中建立 Post 方法，以同步方式呼叫 SP 將資料寫入 DB。

public class LogController : ApiController
{
    string str = "connection string put here";

    private IDbConnection CreateConnection()
    {
        return new SqlConnection(str);
    }

    public IHttpActionResult Post()
    {
        // 以同步方式寫入 LOG
        WriteLog(CreateConnection(), "log testing");

        // 寫入 LOG 結束後才回傳 OK
        return Ok();
    }

    public void WriteLog(IDbConnection cn, string message)
    {
        cn.Execute(
            "usp_write_log_no_return", 
            new { message }, 
            commandType: CommandType.StoredProcedure);
    }

}

 

使用 JMeter 進行 100 次測試，處理時間花費約 1 秒鐘，也就是需完整等待 DB 作業結束後才回應。

100 筆資料確實都順利寫入 DB

 

套用非同步射後不理機制

---

首先將呼叫 SP 方式改為非同步，並將 Web API 程式稍作調整，讓程式在呼叫 WriteLogAsync 後不等待此作業執行完畢就直接回傳 OK。

public class LogController : ApiController
{
    // ... 略 ...

    public IHttpActionResult Post()
    {
        // 以非同步方式寫入 LOG
        var task = WriteLogAsync(CreateConnection(), "log testing");

        // 不會等待 LOG 寫入完畢，直接就回傳 OK
        return Ok();
    }

    public async Task WriteLogAsync(IDbConnection cn, string message)
    {
        await cn.ExecuteAsync(
            "usp_write_log_no_return", 
            new { message }, 
            commandType: CommandType.StoredProcedure);
    }

}

 

使用 JMeter 進行 100 次測試，發現平均僅需花費 6 毫秒就迅速回應，但嚴謹來說只完成「觸發」作業而已，也就是說在回應呼叫端的當下，其實資料尚未寫入 DB 中；由於呼叫端不太在乎執行的結果，所以就讓非同步作業在暗地裡去完成它吧！

100 筆資料確實都順利寫入 DB

為了更明顯呈現此機制特性，筆者故意將時間拉長為 10 秒。

當取樣數到達 100 時，表示所有 Http Request 都已經完成回應，但此時資料尚未寫到 DB 中 (延遲10秒)；我們可以發現其實各個被觸發的非同步 Task 仍然在進行中，直至完成資料寫入作業結束。

 

錯誤處理

---

使用此機制並不代表可以完全忽視錯誤，功能既然存在就必須正確運作，因此還是需要在錯誤發生時留下一些線索；此時有人就會直接用 TRY-CATCH 包起來，期望在錯誤發生時可以記錄下錯誤訊息。

public async Task WriteLogAsync(IDbConnection cn, string message)
{
    try
    {
        await cn.ExecuteAsync(
            "usp_write_log_no_return", 
            new { message }, 
            commandType: CommandType.StoredProcedure);
    }
    catch (Exception)
    {

        // write error log here 
        // ...
    }
            
}

 

BUT 事情沒有這麼單純

這個 Exception 永遠都攔不到！

這個 Exception 永遠都攔不到！

這個 Exception 永遠都攔不到！

 

為什麼會攔不到呢？這就牽涉到非同步程序的運作原理。在使用 async 和 await 時會使用 SynchronizationContext 確保在 await 後接續的作業會回到與 await 前的執行續環境一致，而在 ASP. NET 非同步機制中，每一條 Request 都會使用 AspNetSynchronizationContext 來記錄當下的同步執行緒環境，所以當我們在使用 await 等待非同步作業時，就是透過此物件記錄這個等待位置的 context，並且在非同步作業結束後取得相同 AspNetSynchronizationContext 物件，恢復到先前執行續環境中並繼續執行接下來的程序。

接著回過頭來看一下我們的情境，當等待 cn.ExecuteAsync() 執行非同步作業完畢後，會試圖取得此 Requset 使用的 AspNetSynchronizationContext 物件；但在射後不理的運作機制下，此時該 Request 早就已經終止，因此程式就無法獲得相同 AspNetSynchronizationContext 來接續執行後續的程式碼，所以當然錯誤無法順利被捕捉。

我們可以透過 Task 類別的 ConfigureAwait 方法，給予參數 false 來指定「不要」取得先前使用的 AspNetSynchronizationContext 物件來接續執行 await 後續程式碼，而是使用 TaskScheduler.Default (Thread Pool Context) 以另一條執行緒來完成後續工作。

此時我們的錯誤就可以順利被捕捉，並且接續執行後續程式碼。

 

結論

---

針對量大且不太重要的 LOG 紀錄作業，可以考慮使用非同步射後不理機制來處理，有效減少 Web API 被占用的時間，將資源保留給其他更重要的服務；此外必須注意到 SynchronizationContext 是否還存活，在這種情境下需要設定 ConfigureAwait(false) 來指定「不要」取得先前使用的 SynchronizationContext 物件來接續執行 await 後續程式碼，如此才得以順利執行後續作業。

 

參考資訊

---

ASP.NET 程式鎖死與 SynchronizationContext

await與Task.Result/Task.Wait()的Deadlock問題

---

希望此篇文章可以幫助到需要的人

若內容有誤或有其他建議請不吝留言給筆者喔 !