同事報案,某個 Web API 會不定期出錯。進一步調查是近期啟動的一個新排程同步發出多個 API 呼叫,當 Web API 同時被多方呼叫,Web API 加掛用來寫 Log 的 ActionFilter Attribute 偶爾會發生 Dictionary.Add 重複加入相同鍵值的錯誤。因 Dictionary 被設成 ActionFilter Attribute Instance 的私有欄位,依我原先的理解,ActionFilter Attribute 每次呼叫時都應建立新 Instance,不致因共用打架,但觀察結果顯然與假設不符。進一步檢查 Log 軌跡,確實找到兩次 Request 共用 ActionFilterAttribute 覆寫變數內容的證據!由此,為什麼只在 Instance 執行一次 Dictionary.Add 卻發生鍵值重複便有了合理解釋。

爬文才發現,自 ASP.NET MVC3 起,Action Filter 更積極藉由 Cache 機制重複使用,不再每次 Request 重新建立:參考

In previous versions of ASP.NET MVC, action filters are create per request except in a few cases. This behavior was never a guaranteed behavior but merely an implementation detail and the contract for filters was to consider them stateless. In ASP.NET MVC 3, filters are cached more aggressively. Therefore, any custom action filters which improperly store instance state might be broken.

用以下實例重現問題。用 ActionFilterAttribute 做一個超簡單的執行耗時顯示,在 OnActionExecuting() 以物件欄位記錄 p 參數及開始時間、OnResultExecuted() 計算並顯示耗時及 p 參數:

using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.Linq;
using System.Web;
using System.Web.Mvc;
 
namespace MVCLab.Models
{
    public class ExecTimeAttribute : ActionFilterAttribute
    {
        string id;
        DateTime start;
        public override void OnActionExecuting(ActionExecutingContext filterContext)
        {
            id = filterContext.HttpContext.Request["p"] ?? "NULL";
            start = DateTime.Now;
        }
        public override void OnResultExecuted(ResultExecutedContext filterContext)
        {
            var dura = DateTime.Now - start;
            filterContext.HttpContext.Response.Write($"<span>{id}: {dura.Milliseconds}ms</span>");
        }
    }
}

在 HomeController.cs Index Action 加上 [ExecTime] Attribute:

using MVCLab.Models;
using System;
using System.Collections.Generic;
using System.Linq;
using System.Threading;
using System.Web;
using System.Web.Mvc;
 
namespace MVCLab.Controllers
{
    public class HomeController : Controller
    {
        [ExecTime]
        public ActionResult Index()
        {
            var rnd = new Random();
            Thread.Sleep(rnd.Next(500));
            return View();
        }
    }
}

Index.cshtml 長這様:

@{ Layout = null; }
<!DOCTYPE html>
<html>
<head>
    <meta name="viewport" content="width=device-width" />
    <title>Index</title>
</head>
<body>
    <div>測試(@Request["p"])</div>
</body>
</html>

寫個 Test1.html 做測試:

<!DOCTYPE html>
<html>
<head>
    <meta charset="utf-8" />
    <style>
        iframe { width: 150px; height: 60px; margin: 3px; float: left; }
    </style>
</head>
<body>
    <input id="txtUrl" value="/Home/Index?p=001" />
    <button onclick="test()">Test</button>
    <br />
    <iframe id="frmTest" src="about:blank"></iframe>
    <script>
        function test() {
            document.getElementById("frmTest").src = document.getElementById("txtUrl").value;
        }
    </script>
</body>
</html>

測試結果符合預期:

問題發生在多個 Request 並行時。用三個 IFrame 一次發出 3 個 Request,參數分別傳入 001、002、003:

<!DOCTYPE html>
<html>
<head>
    <title></title>
    <meta charset="utf-8" />
    <style>
        iframe { width: 150px; height: 60px; margin: 3px; float: left; }
    </style>
</head>
<body>
    <iframe src="/Home/Index?p=001"></iframe>
    <iframe src="/Home/Index?p=002"></iframe>
    <iframe src="/Home/Index?p=003"></iframe>
</body>
</html>

然後它就壞掉了!下方顯示的 p 參數全部被覆寫成 003…

由此可知,使用 Attribute 物件屬性或欄位保存狀態可能因物件重複使用導致資料覆寫,故較好的做法是將狀態改存入專屬每個 Request 的 HttpContext.Items 是不錯的選擇。修改後程式如下:

using System;
using System.Web.Mvc;
 
namespace MVCLab.Models
{
    public static class MyContextExt
    {
        public static T GetVar<T>(this ResultExecutedContext ctx, string varName)
        {
            return (T)ctx.HttpContext.Items[varName];
        }
        public static void StoreVar<T>(this ActionExecutingContext ctx, string varName, T data)
        {
            ctx.HttpContext.Items[varName] = data;
        }
    }
 
    public class ExecTimeAttribute : ActionFilterAttribute
    {
        //REF: http://stackoverflow.com/a/8937793/4335757
        public override void OnActionExecuting(ActionExecutingContext filterContext)
        {
            filterContext.StoreVar<string>("id", filterContext.HttpContext.Request["p"] ?? "NULL");
            filterContext.StoreVar<DateTime>("start", DateTime.Now);
        }
        public override void OnResultExecuted(ResultExecutedContext filterContext)
        {
            var dura = DateTime.Now - filterContext.GetVar<DateTime>("start");
            var id = filterContext.GetVar<string>("id");
            filterContext.HttpContext.Response.Write($"<span>{id}: {dura.Milliseconds}ms</span>");
        }
    }
}

改用 HttpContext.Items 保存狀態後,程式運作正常,問題排除。


Comments

# by 阿修

最近剛好有在actionfilter中使用private var, 單一要求測不出問題,真可怕 待會到公司先來改( ̄∇ ̄)

# by 小安

原來之前踩到的是這顆雷... 一直測不出來到底發生什麼事= =" 感謝黑大指點 XD 來改程(ㄗㄠˋ)式(ㄋ一ㄝˋ)

# by demo

在我經手的所有案子我都直接拒絕 ASP. NET MVC TempData 的使用,因為它很容易造成剛從 Web form 轉到 MVC 的開發者把它當萬能的玩意,傳來傳去,造成莫大的效能影響,以及將來 web farm 架構的絆腳石(尤其現在都雲端) 而文中的範例,黑大使用了 HttpContext.Items 來當暫存,並未使用 MVC 的 TempData ,所以我建議直接把文中的 TempData 字眼移除,避免誤會。

# by Jeffrey

to demo, 謝謝指正,我也很反對使用具 Session 性質的共用儲存機制傳遞狀態,一時失察把名詞全搞混了 Orz 已更新本文。

# by ( ̄∇ ̄)

( ̄∇ ̄)

Post a comment