【问题标题】:Why is async await very slow and blocking when exception handling is involved?为什么在涉及异常处理时异步等待非常慢并且阻塞?
【发布时间】:2021-10-06 11:34:02
【问题描述】:
private void buttonLoad_Click(object sender, EventArgs e)
{
    DataTable dt = new DataTable(); //create datatable with 6000 records
    dt.Columns.Add("Name");
    dt.Columns.Add("Value");

    for (int i = 0; i < 2000; i++)
    {
        dt.Rows.Add("Tim", "955");
        dt.Rows.Add("Rob", "511");
        dt.Rows.Add("Steve", "201");
    }

    dataGridView1.DataSource = dt;
}
private async void btnSend_Click(object sender, EventArgs e)
{
    progressBar1.Minimum = 1;
    progressBar1.Maximum = dataGridView1.Rows.Count;
    progressBar1.Value = 1;
    progressBar1.Step = 1;

    List<Task> lstTasks = new List<Task>();

    DataTable dt = (DataTable)dataGridView1.DataSource;

    System.Diagnostics.Stopwatch s = new System.Diagnostics.Stopwatch();
    s.Start();
    foreach (DataRow dr in dt.Rows)
    {
        lstTasks.Add(CallAPIAsync(dr));
    }
    await Task.WhenAll(lstTasks);
    
    MessageBox.Show(s.ElapsedMilliseconds.ToString());
}
private async Task CallAPIAsync(DataRow dr)
{
    try
    {
        await Task.Delay(2000); //simulate post api request that will pass dr[name] and dr[value]

        if (new Random().Next(0,100)>95) //simulate error in the above request
        {
            throw new Exception("Test!");
        }
    }
    catch (Exception e)
    {
        Thread.Sleep(1);//similate sync processing that takes 1ms                
    }

    progressBar1.PerformStep();
}

buttonLoad_Click 我正在将示例数据加载到数据表中。

btnSend_Click 我正在模拟一个异步任务。


在异步任务中,如果你改变了的值

if (new Random().Next(0,100)>95)

if (new Random().Next(0,100)>5)

为了模拟更多的异常,即使catch块只需要1ms,代码也会运行缓慢。

当涉及到异常处理时,为什么 async await 很慢而且阻塞?

【问题讨论】:

  • 想到了上下文切换开销。
  • 你能显示你正在比较的同步代码吗
  • 如果要阻止等待 Db 操作,该任务不会执行任何其他重要职责。
  • 您也可以尝试将“成功”调用移到 try/catch 之后,并将 return 放在 catch 块内。
  • 当抛出更多异常时,代码会变慢多少?你能分享一些指标吗?

标签: c# asynchronous async-await


【解决方案1】:

虽然 cmets 中已经有一些很好的提示,但我发现了一些让我绊倒的点:

您并行运行 2000 个(或您的评论为 6000 个)任务。由于我们在 Winforms 中(WPF 也一样),这些任务中的每一个都将 UI 线程作为同步上下文,这意味着即使你说Task.WhenAll(),它们都必须按顺序执行,因为它们在 UI 线程中运行。

然后在你的代码中你有这个new Random().Next()。这意味着创建了一个新的随机实例,并从当前时间生成种子。这导致了这样一个事实,即您多次产生相同的随机数。当此数字在 95 - 100 范围内时,所有这些任务都会导致 Thread.Sleep(1)(而不是 await Task.Delay(1)),并且由于您在 UI 线程中,您的 UI 将冻结。

所以这里我对你的改进:

  • ui upate 代码中分解你的工作马。当您使用CallAPIAsync(dr).ConfigureAwait(false) 时,代码将在另一个线程中执行,但您不能简单地编写progressBar1.PerformStep(),您必须将其包装在progressBar1.BeginInvoke() 调用中以将该方法分派给UI 线程。

  • 当你在任务世界中时,不要使用Thread.Sleep(),因为一个线程负责多个任务。而是使用await Task.Delay(),以便同一线程中的其他任务可以完成它们的工作。

  • 请注意在 UI 应用程序中使用 async / await 的含义以及您的代码是否将在 UI 线程或其他地方运行。了解在这些情况下如何正确使用.ConfigureAwait(false)

  • 了解new Random()的正确用法。

另外,你能告诉我每个回调是否在运行下一个回调之前完全运行吗?

这个问题有点复杂,不适合评论。所以这是我的答案。

在您当前的实现中,由于缺少 ConfigureAwait(false),您的回调绑定到 UI 线程。所以你所有的任务都必须由 UI 线程处理。它们依次开始,直到到达您的第一个 Task.Delay(2000)。在这里,他们排队等待在两秒钟内进行处理。因为排队 2000 个任务比两秒钟快,你的所有任务或多或少地并行到达这一点。延迟结束后,它们必须由唯一的 UI 线程再次处理。所以它创建了一个新的Random 实例,调用 next 并根据整个过程的结果(注意:UI)线程冻结一毫秒或不冻结。由于您对 Random 类的滥用,您可能会遇到很多异常,如果所有 2000 个任务在 1 毫秒内都遇到异常,则总之会使您的 UI 冻结 2 秒。

【讨论】:

  • 我使用 thread.sleep 作为一些同步工作的占位符。
  • CallAPIAsync(dr).ConfigureAwait(false) 不是意味着这个调用中的所有异步调用也必须标记为 ConfigureAwait false 吗?另外,这个设置是否意味着等待的代码将在单独的线程中运行,或者如您所说的调用本身将在新线程中运行?
  • 如果它不包括ConfigureAwait(false) 建议,我会赞成这个否则很棒的答案。此方法适用于库代码恕我直言。在应用程序代码中,在大多数情况下它是一个 hack。将工作卸载到ThreadPool 线程的正确方法是Task.Run 方法,而将计算结果从后台线程传递到UI 线程的最佳方法是使用通用任务Task&lt;TResult&gt;,如图所示@例如 987654321@。
  • 顺便说一句,我刚刚注意到await 后面有一个progressBar1.PerformStep();。添加ConfigureAwait(false) 将导致该行在非UI 线程上运行(在大多数情况下),很可能导致“调用线程无法访问此对象,因为不同的线程拥有它” 异常.
  • 是的,老实说,我没有仔细阅读您的答案。当我看到.ConfigureAwait(false) 时,我很沮丧,我不得不立即做出反应。 ?
【解决方案2】:

我已经在控制台上运行了它并做了一些更改来比较不同的配置。

  • 无一例外,2000 个任务列表的多次运行耗时 2179 到 2189 毫秒。
  • 以 5% 的几率出现​​异常,他们花了大约 4 秒
  • 以 50% 的几率出现​​异常,他们花了 22-23 秒。
  • 以 75% 的几率出现​​异常,他们花了 31s-33s。
  • 每次都抛出异常,耗时 42s

这接近于线性关系 - 每个异常都会增加大约 20 毫秒。

我对 20 毫秒的第一个猜测是 Thread.Sleep(1) 实际上并不像您希望的那样精确。 documentation 提到了系统时钟分辨率,在 documentation for Task.Delay 的旁注中将其描述为 15 毫秒。秒表似乎证实了睡眠实际上需要 20 毫秒。但实际 CPU 密集型工作只需要 2 毫秒,而不是 40 秒,现在每个任务必须处理异常需要 60 秒。

当我将睡眠持续时间增加到 1000 毫秒时,除了 5% 的例外情况,总持续时间约为 12.2 秒。所以这不仅仅是睡眠时间按顺序累加。

所以我使用了一些调试输出来查看运行 10 个任务时发生的情况,所有任务都会引发导致 1000 毫秒睡眠的异常。我添加了比较任务本地和全局秒表时间的输出:开始、投掷、捕捉、从睡眠中恢复后。

Starting task 1 at: 0ms (task-local) 15ms (global)
Starting task 2 at: 0ms (task-local) 40ms (global)
Starting task 3 at: 0ms (task-local) 41ms (global)
Starting task 4 at: 0ms (task-local) 43ms (global)
Starting task 5 at: 0ms (task-local) 45ms (global)
Starting task 6 at: 0ms (task-local) 47ms (global)
Starting task 7 at: 0ms (task-local) 50ms (global)
Starting task 8 at: 0ms (task-local) 51ms (global)
Starting task 9 at: 0ms (task-local) 53ms (global)
Starting task 10 at: 0ms (task-local) 55ms (global)
Started Thread 2948
Started Thread 15380
Started Thread 17984
Started Thread 11564
Throwing exception in task 7 at: 2016ms (task-local) 2066ms (global)
Throwing exception in task 8 at: 2014ms (task-local) 2066ms (global)
Throwing exception in task 6 at: 2018ms (task-local) 2066ms (global)
Throwing exception in task 5 at: 2020ms (task-local) 2066ms (global)
Caught exception in task 7 at: 2084ms (task-local) 2134ms (global)
Caught exception in task 6 at: 2098ms (task-local) 2145ms (global)
Caught exception in task 5 at: 2102ms (task-local) 2147ms (global)
Caught exception in task 8 at: 2109ms (task-local) 2161ms (global)
Started Thread 15468
Throwing exception in task 9 at: 3015ms (task-local) 3068ms (global)
Caught exception in task 9 at: 3035ms (task-local) 3088ms (global)
Slept for 1s in task 7 at: 3107ms (task-local) 3157ms (global)
Throwing exception in task 4 at: 3118ms (task-local) 3162ms (global)
Slept for 1s in task 5 at: 3118ms (task-local) 3164ms (global)
Slept for 1s in task 6 at: 3115ms (task-local) 3162ms (global)
Slept for 1s in task 8 at: 3122ms (task-local) 3173ms (global)
Throwing exception in task 2 at: 3145ms (task-local) 3185ms (global)
Throwing exception in task 1 at: 3173ms (task-local) 3188ms (global)
Caught exception in task 4 at: 3143ms (task-local) 3187ms (global)
Caught exception in task 2 at: 3179ms (task-local) 3219ms (global)
Caught exception in task 1 at: 3215ms (task-local) 3230ms (global)
Throwing exception in task 3 at: 3142ms (task-local) 3184ms (global)
Caught exception in task 3 at: 3213ms (task-local) 3255ms (global)
Started Thread 27088
Throwing exception in task 10 at: 4010ms (task-local) 4065ms (global)
Caught exception in task 10 at: 4031ms (task-local) 4086ms (global)
Slept for 1s in task 9 at: 4038ms (task-local) 4092ms (global)
Slept for 1s in task 2 at: 4193ms (task-local) 4233ms (global)
Slept for 1s in task 4 at: 4190ms (task-local) 4233ms (global)
Slept for 1s in task 1 at: 4221ms (task-local) 4236ms (global)
Slept for 1s in task 3 at: 4222ms (task-local) 4264ms (global)
Slept for 1s in task 10 at: 5035ms (task-local) 5091ms (global)

将此与输出进行比较,无一例外:

Starting task 1 at: 0ms (task-local) 2ms (global)
Starting task 2 at: 0ms (task-local) 36ms (global)
Starting task 3 at: 0ms (task-local) 38ms (global)
Starting task 4 at: 0ms (task-local) 40ms (global)
Starting task 5 at: 0ms (task-local) 42ms (global)
Starting task 6 at: 0ms (task-local) 46ms (global)
Starting task 7 at: 0ms (task-local) 48ms (global)
Starting task 8 at: 0ms (task-local) 50ms (global)
Starting task 9 at: 0ms (task-local) 53ms (global)
Starting task 10 at: 0ms (task-local) 55ms (global)
Started Thread 12496
Started Thread 16480
Started Thread 10184
Started Thread 17696
Done waiting in task 2 at: 2023ms (task-local) 2059ms (global)
Done waiting in task 5 at: 2016ms (task-local) 2059ms (global)
Done waiting in task 4 at: 2018ms (task-local) 2059ms (global)
Done waiting in task 3 at: 2020ms (task-local) 2059ms (global)
Done waiting in task 1 at: 2066ms (task-local) 2068ms (global)
Done waiting in task 6 at: 2024ms (task-local) 2070ms (global)
Done waiting in task 7 at: 2023ms (task-local) 2071ms (global)
Done waiting in task 10 at: 2017ms (task-local) 2072ms (global)
Done waiting in task 9 at: 2018ms (task-local) 2071ms (global)
Done waiting in task 8 at: 2020ms (task-local) 2071ms (global)

我看到一开始有四个任务一起处理。当他们抛出时,他们正在抛出,一起被捕获和处理,然后他们一起阻塞主线程,然后下一个四个块可以继续,但它开始有点重叠。对于大量任务和异常,异常会以块的形式依次递减 - 可能取决于可用内核的数量?

编写控制台输出当然会弄乱测量,但我看到大约 800 个任务后,2000 毫秒过去了,第一个任务完成等待。因此,虽然并非所有任务都已启动,但第一个异常开始减慢主线程。

看到这一点,我认为在改进它时,这取决于您的实际代码。您可以更改 API 以允许通过一个请求发送多行吗? 也许不要一次单独发送所有 6000 个请求 - 如果一个失败,其余的也可能失败。也许await Task.WhenAll 周围的单个 catch 块就足够了?

更新: 我做了我一开始就应该做的事情,并且在没有淹没控制台的情况下进行了测量。现在更明显的是,捕获每个异常都需要大量时间(>20 毫秒)。这发生在一个线程上,所以一次只有一个例外。当异常处理确实只需要大约 1 毫秒时,切换到 await Task.WhenAll 只会为您节省与异常一样多的毫秒数。

【讨论】:

  • 您所观察到的可能是ThreadPool 饱和的结果。您可以尝试在程序开头添加此行:ThreadPool.SetMinThreads(1000, 1000);,以排除这种可能性。
  • 我很好奇并尝试了它。花费的总时间几乎相同(约 40 秒,100% 例外)。
  • 等待 Task.Delay 的演示代码和发送请求的实际想法都不需要线程,这些(轶事)测量似乎证实了这一点。我发现 this thread 关于限制异步工作,并认为一个重要的问题是应该允许多少请求并行运行。
猜你喜欢
  • 2022-01-17
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
  • 2019-10-16
  • 2022-01-04
  • 1970-01-01
  • 1970-01-01
  • 2017-06-08
相关资源
最近更新 更多