Mock verification slow with It.Is(Expression)

[peterder72]

Mock verification is very slow when used with expressions and large amount of invocations. Repro:

var mock = new Mock<ISimpleObject>();

for (var i = 0; i < 1_000_000; i++)
{
    mock.Object.Do(i);
}

// Takes ~1 minute
mock.Verify(x => x.Do(It.Is<int>(num => num < 10)));

// Takes 0.2s
mock.Verify(x => x.Do(It.IsAny<int>()));

public interface ISimpleObject
{
    void Do(int num);
}

On inspection, most of the time is spent compiling the exact same provided match expression, when predicate is executed for each invocation during verification:

public static TValue Is<TValue>(Expression<Func<TValue, bool>> match)
{
    if (typeof(TValue).IsOrContainsTypeMatcher())
    {
        throw new ArgumentException(Resources.UseItIsOtherOverload, nameof(match));
    }

    var thisMethod = (MethodInfo)MethodBase.GetCurrentMethod();

    return Match.Create<TValue>(
        argument => match.CompileUsingExpressionCompiler().Invoke(argument), // << hot 
        Expression.Lambda<Func<TValue>>(Expression.Call(thisMethod.MakeGenericMethod(typeof(TValue)), match)));
}

This results in huge performance drop on large number of invocations and unnecessary allocations, while not serving any purpose. From what I can see, this issue has not been discovered previously. I was able to trace it back to this commit, but it might've been still present in a different form.

The solution here would be to only execute the compilation once, and then pass the compled delegate into the match factory method:

var thisMethod = (MethodInfo)MethodBase.GetCurrentMethod();
var compiledMethod = match.CompileUsingExpressionCompiler();

return Match.Create<TValue>(
    argument => compiledMethod.Invoke(argument),
    Expression.Lambda<Func<TValue>>(Expression.Call(thisMethod.MakeGenericMethod(typeof(TValue)), match)));

I have implemented a fix on my fork, benchmark results for pre, post, and IsAny (for comparison) is as follows:

BenchmarkDotNet v0.13.8, Arch Linux
AMD Ryzen 9 5900X, 1 CPU, 24 logical and 12 physical cores
.NET SDK 7.0.110
  [Host]   : .NET 7.0.10 (7.0.1023.41001), X64 RyuJIT AVX2
  .NET 7.0 : .NET 7.0.10 (7.0.1023.41001), X64 RyuJIT AVX2

Job=.NET 7.0  Runtime=.NET 7.0  InvocationCount=1  
UnrollFactor=1  

| Method        | Mean         | Error      | StdDev     | Ratio    | RatioSD | Allocated | Alloc Ratio |
|-------------- |-------------:|-----------:|-----------:|---------:|--------:|----------:|------------:|
| RunMoqIs_Pre  | 4,179.471 ms | 81.0558 ms | 83.2384 ms | 1,438.35 |   34.63 | 414.97 MB |      108.38 |
| RunMoqIsAny   |     6.947 ms |  0.1385 ms |  0.1801 ms |     2.40 |    0.07 |  10.87 MB |        2.84 |
| RunMoqIs_Post |     2.899 ms |  0.0411 ms |  0.0364 ms |     1.00 |    0.00 |   3.83 MB |        1.00 |

Benchmark code:

[SimpleJob(RuntimeMoniker.Net70)]
[MemoryDiagnoser(displayGenColumns: false)]
public class CompileBenchmark
{
    private const int NumberOfCalls = 100_000;
    private Mock<ISimpleObject> m_ObjectMock = null!;
    
    [IterationSetup]
    public void Setup()
    {
        m_ObjectMock = new Mock<ISimpleObject>();
        
        for (var i = 0; i < NumberOfCalls; i++)
        {
            m_ObjectMock.Object.Do(i);
        }
        
    }
    
    [Benchmark]
    public void RunMoqIs_Pre()
    {
        m_ObjectMock.Verify(x => x.Do(It.Is_Pre<int>(num => num < 10)));
    }
    
    [Benchmark]
    public void RunMoqIsAny()
    {
        m_ObjectMock.Verify(x => x.Do(It.IsAny<int>()));
    }
    
    [Benchmark(Baseline = true)]
    public void RunMoqIs_Post()
    {
        m_ObjectMock.Verify(x => x.Do(It.Is<int>(num => num < 10)));
    }
}

Since I already have a fix on my fork, I'll be happy to submit a PR for this issue myself

[stakx]

There was another issue a few years ago about caching expression trees to improve performance; IIRC, that was one of the reasons that led to the ExpressionCompiler extension point. You can set ExpressionCompiler.Instance to an instance that caches already compiled expression trees, and Moq will then use that.

IIRC, the reason why the cache wasn't added directly to the default implementation was that there was some uncertainty about how to unambiguously recognize already compiled expression trees and map them to a cached delegate (i.e. how to prevent false positives in the cache lookup).

I suppose if the caching logic is reliable and not overly complex, then that previous decision could be revisited. What does your caching implementation look like?

[peterder72]

@stakx I haven't implemented any caching mechanisms myself, I just fixed the way expressions are compiled for It.Is, see here. This already fixes the biggest performance drop that causes times of 1m for verification

[stakx]

@peterder72, I see. My apologies for the misunderstanding. Looks like a reasonable change to make. 👍

The only thing I'm left wondering is whether compiling the expression tree once, ahead-of-time instead of once per invocation of the matcher could possibly affect how & when captured variables get evaluated. I don't think so, but it may be worth verifying.

[peterder72]

@stakx I was also thinking about the same thing, but I can't see anything that can become an issue here, since nothing is captured in the scope of It.Is, all references come from the caller. If you can think of how it could go wrong so that I can put it under test, let me know, I'll also give it a think for now

[stakx]

@peterder72, I was mostly thinking about things like:

var obj = ...;
... It.Is(x => x == obj) ...
//                  ^^^
// when / how often does this captured variable get evaluated?

But on second thought, even that shouldn't be a problem, since compilation in all probability does not perform any kind of partial evaluation.

I can't think of any other reasons why the change shouldn't be made. Looks good to me.

(Be advised that I am not committing anything to this repo for the time being, due to the recent SponsorLink disaster, so I likely won't be the one merging your PR if you decide to submit one.)

[github-actions]

Due to lack of recent activity, this issue has been labeled as 'stale'.
It will be closed if no further activity occurs within 30 more days.
Any new comment will remove the label.

[kzu]

If you submit a PR for this, I'd gladly merge it.

[peterder72]

Ah, completely forgot about this one, submitted #1512. It's that same fork I used back when I created this issue, but no conflicts it seems