前陣子學會用 Polly TimeoutPolicy 限制執行時間的技巧,套用在某 EF 資料查詢服務,不料沒通過自動測試。用 DbSet<T>.ToList() 查詢全部只有一筆的資料表,卻觸發 Polly 5 秒 Timeout 上限,依直覺查詢本機資料庫再怎麼慢頂多幾百 ms,更甭提沒有 WHERE 條件又只有一筆資料,跑到好幾秒實在很扯。試著用 SQL Profiler 側錄 EF 產生的 SQL 語法,看起來沒什麼問題,丟進 SSMS 執行也是不到 0.1 秒得到結果:

SELECT 
    [Extent1].[Code] AS [Code], 
    [Extent1].[Src] AS [Src], 
    [Extent1].[Name] AS [Name], 
    [Extent1].[Catg] AS [Catg], 
    [Extent1].[Flag1] AS [Flag1], 
    [Extent1].[Flag2] AS [Flag2], 
    [Extent1].[Flag3] AS [Flag3], 
    [Extent1].[Flag4] AS [Flag4], 
    [Extent1].[Flag5] AS [Flag5], 
    [Extent1].[Flag6] AS [Flag6], 
    [Extent1].[Flag7] AS [Flag7]
    FROM [dbo].[FooTable] AS [Extent1]

難道是資料回到 .NET 端處理時踩到雷?我寫了一小段程式單獨測試 EF DbSet<FooTable>.ToList() 跟 Dapper Queryt<FooTable>("SELECT * FROM FooTable").ToList(),用之前發明的 TimeMeasureScope 測量執行時間。

using (var t = new TimeMeasureScope($"LINQ (Outter)"))
{
    using (var ctx = GetEFDbContext())
    {
        using (var it = new TimeMeasureScope($"LINQ (Inner)"))
        {
            var res = ctx.FooTable.ToList();
        }
    }
}
using (var t = new TimeMeasureScope($"Dapper"))
{
    using (var cn = GetConnection())
    {
        var res = cn.Query<FooTable>("SELECT * FROM FooDB.dbo.FooTable").ToList();
    }
}

測試結果讓我震驚,FooTable 只有一筆資料,使用 EF 查詢,若包含建立 DbContext 過程開連線時間耗時 3.3s,DbSet<FooTable>.ToList() 部分則耗時 2.5s;若用 Dapper 查詢只需 68ms。

LINQ (Inner)|2,547ms
LINQ (Outter)|3,285ms
Dapper|68ms

依我的理解,遇到太複雜 LINQ 語法轉出效率不佳的 SQL 語法我可以接受,但這個案例沒加 WHERE 條件又只有一筆,EF 跟 Dapper 居然跑出 3.3s vs 0.07s 的懸殊對比,若這是 EF 的正常表現,哪能逃得過全世界的法眼,勢必要引起一片嘩然,這測試肯定哪裡有問題。

難道是因為先跑 EF 有涉及建立 SQL 連線被拖慢,改成先跑 Dapper 再跑 EF,Dapper 也不到一秒,EF 還是接近 3 秒。但這點提醒我,.NET 第一次執行會因為組件載入、靜態建構式、靜態屬性、初始化程序、JIT 編譯(載入組件、呼叫方法前)... 等動作較慢(延伸閱讀:.NET 效能測試首次執行偏慢現象解析.NET 首次執行偏慢現象之 JIT 編譯效應觀察),只測一次易失真。

修改程式,改成測試三次:

for (var i = 1; i <= 3; i++) 
{
    using (var t = new TimeMeasureScope($"Test {i}. LINQ (Outter)"))
    {
        using (var ctx = GetEFDbContext())
        {
            using (var it = new TimeMeasureScope($"Test {i}. LINQ (Inner)"))
            {
                var res = ctx.FooTable.ToList();
            }
        }
    }
    using (var t = new TimeMeasureScope($"Test {i}. Dapper"))
    {
        using (var cn = GetConnection())
        {
            var res = cn.Query<FooTable>("SELECT * FROM FooDB.dbo.FooTable").ToList();
        }
    }
}

測試結果印證了 EF 跟 Dapper 的第一次執行都最慢的,分別為 3 秒跟 0.07 秒,之後數字就合理許多,二者都在 30ms 以內。

Test 1. LINQ (Inner)|2,439ms
Test 1. LINQ (Outter)|3,088ms
Test 1. Dapper|70ms
Test 2. LINQ (Inner)|17ms
Test 2. LINQ (Outter)|19ms
Test 2. Dapper|12ms
Test 3. LINQ (Inner)|19ms
Test 3. LINQ (Outter)|21ms
Test 3. Dapper|11ms

調換順序,先測 Dapper 再測 EF,則首次 Dapper 耗時 0.6 秒,EF 為 2.4 秒:

Test 1. Dapper|638ms
Test 1. LINQ (Inner)|2,004ms
Test 1. LINQ (Outter)|2,411ms
Test 2. Dapper|35ms
Test 2. LINQ (Inner)|28ms
Test 2. LINQ (Outter)|30ms
Test 3. Dapper|10ms
Test 3. LINQ (Inner)|12ms
Test 3. LINQ (Outter)|14ms

這是我可以接受的結果,你無法要求 iPhone 跟 Nokia 3310 一樣省電,功能愈多愈複雜,就得消耗更多資源,雖然第一次執行耗時到 3 秒有點超乎預期,之後的執行速度倒還正常。但即然已知此一特性,若是對速度極度敏感的應用情境(例如:出現一次超過兩秒就要寫檢討報告),可能需要透過 IIS Application Initialization (Preload) 等技巧改善。

Case of simple EF query exceeds timeout in the first run.


Comments

Be the first to post a comment

Post a comment