c# - 使用 StopWatch 类获取 C# 方法的正确执行时间

Question

我一直stopwatch在我的一个DevExpress基于应用程序中使用。我创建了一个FlaUI基于测试用例，它启动keyboard，输入一个值，然后移动到下一列。现在，在我使用的 DevExpress 网格中，一行中有 20 多列。当我尝试运行该测试用例 5 次以达到基准时间时，我看到了太多不同的结果。

我在此处粘贴当前代码的摘录：

 public bool CreateNewGdistVoyageForPerformanceTesting(IEnumerable<GdistBenchVoyageParameters> gdistparameters,
        string gridAutomationId)
    {
        var watch = System.Diagnostics.Stopwatch
            .StartNew(); //This line of code is being used to monitor the time taken by each Keyboard operation

        long TotalTimeConsumed = 0;
        int MaxAllowedTime = 0;
        int HasTimeExceeded = 0;
        bool TimeHasNotExceeded = true;

        watch.Start();
        _logger.Info("Creating a new GDIST Voyage");
        TabItem ParentControl = VoyageEditorTabControl.SelectedTabItem;
        var CurrentSelectedTab = VoyageEditorTabControl.SelectedTabItemIndex;
        var ParentGrid = VoyageEditorTabControl.TabItems[CurrentSelectedTab]
            .FindFirstDescendant(cf => cf.ByAutomationId(gridAutomationId)).AsGrid();
        _controlAction.Highlight(ParentGrid);
        var Pattern = ParentGrid.Patterns.Grid;
        var RowCount = Pattern.Pattern.RowCount;
        var ColumnCount = Pattern.Pattern.ColumnCount;
        _logger.Info("======================================================================================");
        if (ParentGrid.AutomationId.Equals("ParentGridControl"))
        {
            _logger.Info($"Performance Testing on GDIST's View Main Grid :{gridAutomationId}");
            _logger.Info($"Current Grid Row count is: {RowCount}");

            _logger.Info("Creating a new voyage for GDIST Bench");
        }
        else
        {
            _logger.Info($"Performance Testing on GDIST's  Similar Voyages Panel Grid: {gridAutomationId}");
            _logger.Info($"Current Grid Row count is: {RowCount}");
            _logger.Info("Editing an existing voyage for GDIST Bench's Similar Voyages Panel");

        }

        for (int i = 0; i < ColumnCount; i++)
        {
            var cell = ParentGrid.Patterns.Grid.Pattern.GetItem(ParentGrid.RowCount - 1, i);

            if (cell == null)
            {
                _logger.Warning("No Columns found with matching Automation Ids");

                break;
            }

            if (cell.AutomationId.Equals("Vessel"))
            {
                MaxAllowedTime = 1500;
                gdistparameters.ToList().ForEach(voyageDetailsField =>
                {

                    if (voyageDetailsField.VesselId != null)
                    {
                        _logger.Info("Adding Data in Vessel ID  ");
                        cell.Focus();
                        cell.Click();
                        _logger.Info($"Entered value is:{voyageDetailsField.VesselId}");
                        watch.Stop(); // trying this to ensure the watch dummy run to remove JIT noise
                        if (!watch.IsRunning)
                        {
                            watch.Restart(); //starting the watch
                        }
                        Keyboard.Type(voyageDetailsField.VesselId.Trim());
                        watch.Stop();
                        Keyboard.Press(VirtualKeyShort.TAB);
                        //  _controlAction.WaitFor(new TimeSpan(0, 0, 2));
                        Wait.UntilInputIsProcessed();

                        _logger.Info($"Execution Time: {watch.ElapsedMilliseconds} ms");
                        if (watch.ElapsedMilliseconds > MaxAllowedTime)
                        {
                            HasTimeExceeded++;
                            _logger.Warning($"The data entry time has exceeded beyond the fixed value by {watch.ElapsedMilliseconds - MaxAllowedTime} ms");
                        }
                        TotalTimeConsumed = TotalTimeConsumed + watch.ElapsedMilliseconds;
                    }
                });


                TotalTimeConsumed = TotalTimeConsumed + watch.ElapsedMilliseconds;

            }



            if (cell.AutomationId.Equals("LoadDate")) //Load Date
            {
                MaxAllowedTime = 500;
                gdistparameters.ToList().ForEach(voyageDetailsField =>
                {
                    //  _logger.Info("Adding data into the Load Date field");

                    if (voyageDetailsField.LoadDate != null)
                    {
                        _logger.Info("Adding Data in Load Date ");
                        cell.Focus();
                        cell.Click();
                        _logger.Info($"Entered value is:{voyageDetailsField.LoadDate}");
                        watch.Stop(); // trying this to ensure the watch dummy run to remove JIT noise
                        if (!watch.IsRunning)
                        {
                            watch.Restart(); //starting the watch
                        }

                        Keyboard.Type(voyageDetailsField.LoadDate.Trim());
                        watch.Stop();
                        Keyboard.Press(VirtualKeyShort.TAB);
                        //  _controlAction.WaitFor(new TimeSpan(0, 0, 2));
                        Wait.UntilInputIsProcessed();

                        _logger.Info($"Execution Time: {watch.ElapsedMilliseconds} ms");
                        if (watch.ElapsedMilliseconds > MaxAllowedTime)
                        {
                            HasTimeExceeded++;
                            _logger.Warning(
                                $"The data entry time has exceeded beyond the fixed value by {watch.ElapsedMilliseconds - MaxAllowedTime} ms");
                        }

                        TotalTimeConsumed = TotalTimeConsumed + watch.ElapsedMilliseconds;
                    }
                });


                TotalTimeConsumed = TotalTimeConsumed + watch.ElapsedMilliseconds;



            }

我通过logger功能观察到的时间如下。

我已经在多台 PC、多个环境中运行过它，但结果却大不相同。第五次运行实际上在每种情况下都需要很多。

另请注意，在应用程序加载时输入的所有数据都会被填充，因此网络延迟在这里应该不是问题。

此外，我读到 StopWatch 带有很多 JIT 噪音，是的，我每次第一次运行它时都经历过，所以我已经在我的代码中给了它一个错误的开始。

此测试是性能测试，需要进行基准测试。我们可以在数字差异如此之大的情况下决定基准测试。