C#中Stopwatch分段计时与总耗时不符问题求助

我正在优化一段处理约1400个UserPrincipal的代码，目前耗时达3.8-4.4秒，远超预期。使用Stopwatch测量函数内各段代码耗时后，发现分段计时总和与总计时存在显著差距，无法定位耗时来源，恳请提供排查思路。

测量SamAccountName的耗时是因为了解到该属性的getter实现可能存在性能问题。

函数代码 #

private static ConcurrentDictionary<string, User> ProcessUsers(List<UserPrincipal> users)
{
    ConcurrentDictionary<string, User> toReturn = new ConcurrentDictionary<string, User>(4, 2000);
    Regex regex = new Regex(@"^[a-zA-Z]{3}(\d{4})$");         

    Parallel.ForEach(users, user =>
    {
        Stopwatch timerSamAccountName = new Stopwatch();
        Stopwatch timerIfBlock = new Stopwatch();
        Stopwatch timerTotal = new Stopwatch();

        timerTotal.Start();

        timerSamAccountName.Start();
        string guid = user.SamAccountName;
        timerSamAccountName.Stop();
        Console.WriteLine($"SamAccountName done in {timerSamAccountName.Elapsed} for {user.Name}");

        timerIfBlock.Start();
        if (regex.IsMatch(guid))
        {
            User newUser = new User(user.Name, guid.ToUpper(), user.EmailAddress, user); 
            toReturn.TryAdd(newUser.ID, newUser);
        }
        timerIfBlock.Stop();
        Console.WriteLine($"IF block done in {timerIfBlock.Elapsed} for {user.Name}");
        
        timerTotal.Stop();
        Console.WriteLine($"User processed in {timerTotal.Elapsed} for {user.Name}");
    });
    return toReturn;
}

User类代码 #

internal class User
{
    public string name { get; set; }
    public string ID { get; set; }
    public string email { get; set; }
    public UserPrincipal? activeDirectoryHandle { get; set; }

    public User(string inName = "None", string inID = "None", string inEmail = "None", UserPrincipal? adHandle = null)
    {
        name = inName;
        ID = inID;
        email = inEmail;
        activeDirectoryHandle = adHandle;
    }
}

计时差异情况 #

从输出可见，单个用户的总耗时（例如约15ms）远大于SamAccountName耗时（约0.1ms）与IF块耗时（约0.05ms）的总和，两者之间存在明显的时间缺口。

排查思路 #

• 修正并行环境下的计时干扰：Parallel.ForEach多线程执行时，Console.WriteLine会触发线程同步锁，这部分耗时未被计入分段计时，但会算入总计时。建议先将计时结果存入线程安全集合（如ConcurrentBag），最后统一输出，避免控制台输出带来的额外耗时干扰。
• 全面检查AD属性访问的隐性耗时：除了SamAccountName，构造User对象时还访问了user.Name和user.EmailAddress，这些AD属性的getter可能存在延迟加载逻辑，第一次访问时会触发AD服务器查询，这部分耗时未被当前分段计时覆盖。需单独测量这两个属性的访问耗时。
• 排查ConcurrentDictionary的锁竞争：toReturn.TryAdd在高并发场景下可能产生锁竞争，虽然该操作被包含在IF块计时内，但多线程同时写入时的等待时间会拉高整体总耗时。可尝试先将符合条件的User收集到普通列表，最后一次性写入ConcurrentDictionary，或更换为更轻量的并发容器（如System.Collections.Frozen命名空间下的容器，若使用.NET 6+）。
• 优化Regex的执行效率：将Regex实例改为编译模式（new Regex(@"^[a-zA-Z]{3}(\d{4})$", RegexOptions.Compiled)），提升匹配速度；同时确认Regex实例的复用是否正确（当前代码已做到外层创建，无需在循环内重复创建）。
• 测量并行调度的额外开销：在Parallel.ForEach外层包裹一个全局Stopwatch，对比所有单用户总计时的累加和与全局总计时的差距，该差值即为并行调度、线程切换、同步等带来的系统开销。
• 检查User构造的隐性操作：User构造函数中直接赋值activeDirectoryHandle = adHandle，是否存在隐性的对象绑定或复制操作？可暂时注释掉该赋值逻辑，观察耗时变化，判断是否为耗时来源。

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