在异步任务中使用MVC迷你分析器计时

本文关键字:分析器 MVC 异步 任务 | 更新日期: 2023-09-27 18:16:15

我在一个页面内有一个长时间运行的SQL查询,我通过使用异步任务来加速:

using System.Threading.Tasks;
...
var asyncTask = new Task<ResultClass>(
    () =>
    {
        using (var stepAsync = MiniProfiler.Current.Step("Async!"))
        {
            // exec long running SQL
        }
    });
asyncTask.Start();
// do lots of other slow stuff
ResultClass result;
using (var stepWait = MiniProfiler.Current.Step("Wait for Async"))
{
    result = asyncTask.Result;
}

(注意,一旦c# 5推出asyncawait,这种语法将会好得多)

当使用MVC迷你分析器时,我得到了"等待异步"的时间,但我不能得到"异步!"步骤的时间。

是否有任何方法可以将这些结果(可能只是SQL计时)放入已完成页面的跟踪中?

我已经找到了一种方法,使剖析器步骤进入async方法:

var asyncTask = new Task<ResultClass>(
    profiler =>
    {
        using (var step = (profiler as MiniProfiler).Step("Async!"))
        {
            // exec long running SQL
        }
    }, MiniProfiler.Current);

这几乎可以工作,因为出现了"Async!"步骤(根据执行情况,有些随机,有时显示为负数),但这并不是我真正想要的。SQL计时和语句仍然会丢失,在这种情况下,它们是最有价值的信息。

理想情况下,我希望"等待异步"步骤链接到计时(而不是开始步骤)。是否有一些方式,stepWait可以链接到SQL分析器的时间为结果?

任何想法?

在异步任务中使用MVC迷你分析器计时

我找到了一种方法来做到这一点,通过只保持SQL计时,主要页面步骤仍然加起来正确:

var asyncTask = new Task<T>(
    profiler =>
    {
        var currentProfiler = (profiler as MiniProfiler);
        // Create a new profiler just for this step, we're only going to use the SQL timings
        MiniProfiler newProfiler = null;
        if (currentProfiler != null)
        {
            newProfiler = new MiniProfiler("Async step", currentProfiler.Level);
        }
        using(var con = /* create new DB connection */)
        using(var profiledCon = new ProfiledDbConnection(con, newProfiler))
        {
            // ### Do long running SQL stuff ###
            profiledCon.Query...
        }
        // If we have a profiler and a current step
        if (currentProfiler != null && currentProfiler.Head != null)
        {
            // Add the SQL timings to the step that's active when the SQL completes
            var currentStep = currentProfiler.Head;
            foreach (var sqlTiming in newProfiler.GetSqlTimings())
            {
                currentStep.AddSqlTiming(sqlTiming);
            }
        }
        return result;
    }, MiniProfiler.Current);

这会导致长时间运行查询的SQL计时与SQL完成时的当前步骤相关联。通常,这是等待异步结果的步骤,但如果SQL在我必须等待此之前完成,则将是更早的步骤。

我把它包装在一个dapper风格的QueryAsync<T>扩展方法中(总是缓冲的,不支持事务),尽管它可以做很多整理。当我有更多的时间时,我会考虑添加一个ProfiledTask<T>或类似的,允许从完成的任务中复制分析结果。

更新1

按照Sam的评论(见下文),他是完全正确的:AddSqlTiming不是线程安全的。为了解决这个问题,我把它移到了同步延续中:

// explicit result class for the first task
class ProfiledResult<T>
{
    internal List<SqlTiming> SqlTimings { get; set; }
    internal T Result { get; set; }
}
var currentStep = MiniProfiler.Current.Head;
// Create a task that has its own profiler
var asyncTask = new Task<ProfiledResult<T>>(
    () =>
    {
        // Create a new profiler just for this step, we're only going to use the SQL timings
        var newProfiler = new MiniProfiler("Async step");
        var result = new ProfiledResult<T>();
        result.Result = // ### Do long running SQL stuff ###
        // Get the SQL timing results
        result.SqlTimings = newProfiler.GetSqlTimings();
        return result;
    });
// When the task finishes continue on the main thread to add the SQL timings
var asyncWaiter = asyncTask.ContinueWith<T>(
    t =>
    {
        // Get the wrapped result and add the timings from SQL to the current step
        var completedResult = t.Result;
        foreach (var sqlTiming in completedResult.SqlTimings)
        {
            currentStep.AddSqlTiming(sqlTiming);
        }
        return completedResult.Result;
    }, TaskContinuationOptions.ExecuteSynchronously);

asyncTask.Start();
return asyncWaiter;

这可以在MvcMiniProfiler 1.9中工作,但不能在MiniProfiler 2中工作…

更新2:MiniProfiler>=2

版本2中添加的EF内容打破了我上面的hack(它添加了一个仅用于内部的IsActive标志),这意味着我需要一种新的方法:为异步任务实现BaseProfilerProvider:

public class TaskProfilerProvider<T> :
    BaseProfilerProvider
{
    Timing step;
    MiniProfiler asyncProfiler;
    public TaskProfilerProvider(Timing parentStep)
    {
        this.step = parentStep;
    }
    internal T Result { get; set; }
    public override MiniProfiler GetCurrentProfiler()
    {
        return this.asyncProfiler;
    }
    public override MiniProfiler Start(ProfileLevel level)
    {
        var result = new MiniProfiler("TaskProfilerProvider<" + typeof(T).Name + ">", level);
        this.asyncProfiler = result;
        BaseProfilerProvider.SetProfilerActive(result);
        return result;
    }
    public override void Stop(bool discardResults)
    {
        if (this.asyncProfiler == null)
        {
            return;
        }
        if (!BaseProfilerProvider.StopProfiler(this.asyncProfiler))
        {
            return;
        }
        if (discardResults)
        {
            this.asyncProfiler = null;
            return;
        }
        BaseProfilerProvider.SaveProfiler(this.asyncProfiler);
    }
    public T SaveToParent()
    {
        // Add the timings from SQL to the current step
        var asyncProfiler = this.GetCurrentProfiler();
        foreach (var sqlTiming in asyncProfiler.GetSqlTimings())
        {
            this.step.AddSqlTiming(sqlTiming);
        }
        // Clear the results, they should have been copied to the main thread.
        this.Stop(true);
        return this.Result;
    }
    public static T SaveToParent(Task<TaskProfilerProvider<T>> continuedTask)
    {
        return continuedTask.Result.SaveToParent();
    }
}

所以要使用这个提供程序,我只需要在启动任务时启动它,并同步连接延续(像以前一样):

// Create a task that has its own profiler
var asyncTask = new Task<TaskProfilerProvider<T>>(
    () =>
    {
        // Use the provider to start a new MiniProfiler
        var result = new TaskProfilerProvider<T>(currentStep);
        var asyncProfiler = result.Start(level);
        result.Result = // ### Do long running SQL stuff ###
        // Get the results
        return result;
    });
// When the task finishes continue on the main thread to add the SQL timings
var asyncWaiter = asyncTask.ContinueWith<T>(
    TaskProfilerProvider<T>.SaveToParent, 
    TaskContinuationOptions.ExecuteSynchronously);
asyncTask.Start();
return asyncWaiter;

现在,SQL计时一致地显示针对启动异步操作的步骤。虽然sql中的"% "大于100%,但额外的82.4%是通过并行执行sql节省的时间。

                   duration (ms)  from start (ms)  query time (ms)
Start ...Async     0.0            +19.0            1 sql    4533.0
Wait for ...Async  4132.3         +421.3
                                                    182.4 % in sql

理想情况下,我应该在等待步骤而不是init步骤上运行长时间运行的SQL查询,但是如果不改变调用方法的返回类型以显式地传递计时(这会使分析器相当引人注目),我无法做到这一点。

你所能做的就是创建一个新的分析器,并将其附加到web分析器。

var newProfiler = new MiniProfiler("- Other task (discard this time)", ProfileLevel.Verbose);
MiniProfiler.Current.AddProfilerResults(newProfiler);
var asyncTask = new Task(() =>
{
    using (newProfiler.Step("Async!"))
    {
        Thread.Sleep(500);
        using (newProfiler.Step("Async 2!"))
        {
            Thread.Sleep(1000);
        }
    }
});
asyncTask.Start();

新的分析器在它的声明中将会有错误的时间,但是这些步骤是可以的