.NET Core(Dapper)下SQLite查询随机出现150ms额外延迟问题

问题基础信息 #

• 技术栈：.NET Core 3.1，分别测试两种数据访问方案，异常表现完全一致：
  • Dapper 2.0.78 + Microsoft.Data.Sqlite 3.1.25
  • EF Core，依赖包版本Microsoft.EntityFrameworkCore.Sqlite 3.1.22
• 异常表现：部分SELECT查询会随机比正常查询多耗时约150ms，延迟全部出现在查询执行阶段，结果集遍历无额外耗时
• 已确认的问题特征：
  • 与运行环境无关，本地开发机即可复现
  • 与数据库数据量无关，空数据库场景下也可触发
  • 异常出现时无任何并发写入操作，全程仅存在读请求

并发测试耗时统计 #

执行1000次并发查询测试，部分耗时日志如下：

734. All=8 ms, Query=8 ms, ToList=0ms
735. All=2 ms, Query=2 ms, ToList=0ms
736. All=2 ms, Query=2 ms, ToList=0ms
737. All=4 ms, Query=4 ms, ToList=0ms
738. All=3 ms, Query=3 ms, ToList=0ms
739. All=2 ms, Query=2 ms, ToList=0ms
740. All=158 ms, Query=158 ms, ToList=0ms
741. All=2 ms, Query=2 ms, ToList=0ms
742. All=1 ms, Query=1 ms, ToList=0ms
743. All=1 ms, Query=1 ms, ToList=0ms
744. All=1 ms, Query=1 ms, ToList=0ms
745. All=158 ms, Query=158 ms, ToList=0ms
746. All=1 ms, Query=1 ms, ToList=0ms
747. All=158 ms, Query=158 ms, ToList=0ms
748. All=2 ms, Query=2 ms, ToList=0ms
749. All=157 ms, Query=157 ms, ToList=0ms
750. All=1 ms, Query=1 ms, ToList=0ms
751. All=3 ms, Query=3 ms, ToList=0ms
752. All=1 ms, Query=1 ms, ToList=0ms
753. All=1 ms, Query=1 ms, ToList=0ms
754. All=3 ms, Query=3 ms, ToList=0ms
755. All=1 ms, Query=1 ms, ToList=0ms
756. All=1 ms, Query=1 ms, ToList=0ms
757. All=1 ms, Query=1 ms, ToList=0ms
758. All=1 ms, Query=1 ms, ToList=0ms
759. All=1 ms, Query=1 ms, ToList=0ms
760. All=1 ms, Query=1 ms, ToList=0ms
761. All=5 ms, Query=5 ms, ToList=0ms
762. All=1 ms, Query=1 ms, ToList=0ms

问题复现代码 #

public static void Main(string[] args)
{
    var tasks = new List<Task>();
    var times = new List<TimeInfo>();
    Stopwatch sw = new Stopwatch();

    for (int i = 1; i <= 1000; i++)
    {
        var j = i * 1;
        tasks.Add(Task.Run(() =>
        {
            Stopwatch sw = new Stopwatch();
            Stopwatch swAll = new Stopwatch(); 
            swAll.Start();
            sw.Start();
            IEnumerable<Cross> result;
            using (var cnn = new SqliteConnection("Data Source=crosses.db"))
            {
                result = cnn.Query<Cross>("SELECT * FROM Crosses WHERE ArticleId=2106053  AND Source=7");
            }
            var timeRequest = sw.ElapsedMilliseconds;
            sw.Restart();
            var list = result.ToList();
            sw.Stop();
            var timeToList = sw.ElapsedMilliseconds;
            swAll.Stop();
            times.Add(new TimeInfo()
            {
                I = j,
                TimeAll = swAll.ElapsedMilliseconds,
                TimeQuery = timeRequest,
                TimeToList = timeToList,
            });
        }));
    }

    Task.WaitAll(tasks.ToArray());
    foreach (var item in times.OrderBy(w => w.I))
    {
        Console.WriteLine("{0}. All={1} ms, Query={2} ms, ToList={3}ms", item.I, item.TimeAll, item.TimeQuery, item.TimeToList);
    }
    Console.ReadKey();
}

数据库表结构 #

测试库仅包含单表Crosses，已为查询条件字段ArticleId、Source创建联合索引，结构定义如下：

create table Crosses
(
    Id             INTEGER not null
        constraint PK_Crosses
            primary key autoincrement,
    ArticleId      INTEGER not null,
    CrossId        INTEGER not null,
    CrossBrand     TEXT,
    CrossArticle   TEXT,
    Source         INTEGER not null,
    AdditionalInfo TEXT
);

create index IX_Crosses_ArticleId_Source
    on Crosses (ArticleId, Source);

内容的提问来源于stack exchange，提问作者Evgeny Tsaplinov