[11.0.100-preview.4.26224.122] GlobalToolsNETCore21Part02 execute "dotnet vstest" failed with “Moq.MockException : Expected invocation on the mock at least once, but was never performed”

[WeiweiCaiAcpt]

Description

Prior to dotnet-sdk-11.0.100-preview.4.26224.122, running "dotnet vstest DockerWatch.Test.dll" resulted in a System.TypeLoadException when using dotnet-sdk-11.0.100-preview.4.26210.111 and dotnet-sdk-11.0.100-preview.4.26214.103 (refer to: [dotnet-sdk-11.0.100-preview.4.26214.103] GlobalToolsNETCore21Part02 execute "dotnet vstest" failed with error: System.TypeLoadException : Could not load type 'Microsoft.Extensions.Logging.Internal.FormattedLogValues'... · Issue #126995 · dotnet/runtime).
Starting from dotnet-sdk-11.0.100-preview.4.26224.122, the System.TypeLoadException no longer occurs; however, it is replaced by a new Moq.MockException, as shown below:

Moq.MockException :

Expected invocation on the mock at least once, but was never performed: m => m.Log<Object>(LogLevel.Trace, It.IsAny<EventId>(), It.Is<FormattedLogValues>(v => v.ToString().Contains("trace")), It.IsAny<Exception>(), It.IsAny<Func<Object, Exception, String>>())
No setups configured.

Performed invocations:
ILogger.Log<FormattedLogValues>(LogLevel.Trace, 0, [[{OriginalFormat}, trace]], null, Func<FormattedLogValues, Exception, String>)
  Stack Trace:
     at Moq.Mock.VerifyCalls(Mock targetMock, InvocationShape expectation, LambdaExpression expression, Times times, String failMessage)
   at Moq.Mock.Verify[T](Mock`1 mock, Expression`1 expression, Times times, String failMessage)
   at Moq.Mock`1.Verify(Expression`1 expression)
   at DockerWatch.Test.LoggerAdapterTest.LogInformation_ShouldLogTraceMessages() in C:\Users\v-joyzhu\Desktop\unit test\docker-watch-master\docker-watch-master\test\DockerWatch.Test\LoggerAdapterTest.cs:line 63
   at System.Reflection.MethodBaseInvoker.InterpretedInvoke_Method(Object obj, IntPtr* args)
   at System.Reflection.MethodBaseInvoker.InvokeWithNoArgs(Object obj, BindingFlags invokeAttr)

More detailed information, please see the devdiv bug.

Reproduction Steps

Environment Configuration:
The machine has dotnet-sdk-11.0.0-preview.4.26224.122 installed.

1. Copy GlobalToolsNETCore21Part02Test56 from shared server (see location from devdiv bug) to local machine.
2. Modify DockerWatch.Test.runtimeconfig.json to enable the app to run on dotnet-sdk-11.0.0-preview.4.26224.122.
   "framework": {
   "name": "Microsoft.NETCore.App",
   "version": "11.0.0-preview.4.26224.122"
   }

Repro Steps:

1. Open cmd in GlobalToolsNETCore21Part02Test56.
2. Execute command: dotnet vstest DockerWatch.Test.dll.

Expected behavior

Passed! - Failed: 0, Passed: 18, Skipped: 0, Total: 18, Duration: 3 s - DockerWatch.Test.dll

Actual behavior

3 test cases failed with below error:
[xUnit.net 00:00:03.70] DockerWatch.Test.LoggerAdapterTest.LogInformation_ShouldLogTraceMessages [FAIL]
[xUnit.net 00:00:03.71] DockerWatch.Test.LoggerAdapterTest.LogInformation_ShouldLogAnErrorMessage [FAIL]
[xUnit.net 00:00:03.72] DockerWatch.Test.LoggerAdapterTest.LogInformation_ShouldLogAnInformationMessage [FAIL]
Failed DockerWatch.Test.LoggerAdapterTest.LogInformation_ShouldLogTraceMessages [94 ms]
Error Message:
Moq.MockException :
Expected invocation on the mock at least once, but was never performed: m => m.Log(LogLevel.Trace, It.IsAny(), It.Is(v => v.ToString().Contains("trace")), It.IsAny(), It.IsAny<Func<Object, Exception, String>>())
No setups configured.

Performed invocations:
ILogger.Log(LogLevel.Trace, 0, [[{OriginalFormat}, trace]], null, Func<FormattedLogValues, Exception, String>)
Stack Trace:
at Moq.Mock.VerifyCalls(Mock targetMock, InvocationShape expectation, LambdaExpression expression, Times times, String failMessage)
at Moq.Mock.Verify[T](Mock1 mock, Expression1 expression, Times times, String failMessage)
at Moq.Mock1.Verify(Expression1 expression)
at DockerWatch.Test.LoggerAdapterTest.LogInformation_ShouldLogTraceMessages() in C:\Users\v-joyzhu\Desktop\unit test\docker-watch-master\docker-watch-master\test\DockerWatch.Test\LoggerAdapterTest.cs:line 63
at System.Reflection.MethodBaseInvoker.InterpretedInvoke_Method(Object obj, IntPtr* args)
at System.Reflection.MethodBaseInvoker.InvokeWithNoArgs(Object obj, BindingFlags invokeAttr)
Failed DockerWatch.Test.LoggerAdapterTest.LogInformation_ShouldLogAnErrorMessage [12 ms]
Error Message:
Moq.MockException :
Expected invocation on the mock at least once, but was never performed: m => m.Log(LogLevel.Error, It.IsAny(), It.Is(v => v.ToString().Contains("error")), It.IsAny(), It.IsAny<Func<Object, Exception, String>>())
No setups configured.

Performed invocations:
ILogger.Log(LogLevel.Error, 0, [[{OriginalFormat}, error]], null, Func<FormattedLogValues, Exception, String>)
Stack Trace:
at Moq.Mock.VerifyCalls(Mock targetMock, InvocationShape expectation, LambdaExpression expression, Times times, String failMessage)
at Moq.Mock.Verify[T](Mock1 mock, Expression1 expression, Times times, String failMessage)
at Moq.Mock1.Verify(Expression1 expression)
at DockerWatch.Test.LoggerAdapterTest.LogInformation_ShouldLogAnErrorMessage() in C:\Users\v-joyzhu\Desktop\unit test\docker-watch-master\docker-watch-master\test\DockerWatch.Test\LoggerAdapterTest.cs:line 43
at System.Reflection.MethodBaseInvoker.InterpretedInvoke_Method(Object obj, IntPtr* args)
at System.Reflection.MethodBaseInvoker.InvokeWithNoArgs(Object obj, BindingFlags invokeAttr)
Failed DockerWatch.Test.LoggerAdapterTest.LogInformation_ShouldLogAnInformationMessage [8 ms]
Error Message:
Moq.MockException :
Expected invocation on the mock at least once, but was never performed: m => m.Log(LogLevel.Information, It.IsAny(), It.Is(v => v.ToString().Contains("information")), It.IsAny(), It.IsAny<Func<Object, Exception, String>>())
No setups configured.

Performed invocations:
ILogger.Log(LogLevel.Information, 0, [[{OriginalFormat}, information]], null, Func<FormattedLogValues, Exception, String>)
Stack Trace:
at Moq.Mock.VerifyCalls(Mock targetMock, InvocationShape expectation, LambdaExpression expression, Times times, String failMessage)
at Moq.Mock.Verify[T](Mock1 mock, Expression1 expression, Times times, String failMessage)
at Moq.Mock1.Verify(Expression1 expression)
at DockerWatch.Test.LoggerAdapterTest.LogInformation_ShouldLogAnInformationMessage() in C:\Users\v-joyzhu\Desktop\unit test\docker-watch-master\docker-watch-master\test\DockerWatch.Test\LoggerAdapterTest.cs:line 23
at System.Reflection.MethodBaseInvoker.InterpretedInvoke_Method(Object obj, IntPtr* args)
at System.Reflection.MethodBaseInvoker.InvokeWithNoArgs(Object obj, BindingFlags invokeAttr)

Failed! - Failed: 3, Passed: 15, Skipped: 0, Total: 18, Duration: 3 s - DockerWatch.Test.dll (netcoreapp2.1)

Regression?

Yes.

Verify Scenarios:
1). Windows 11 24H2 AMD64 + dotnet-sdk-11.0.100-preview.3.26207.106: Pass
2). Windows 11 24H2 AMD64 + dotnet-sdk-11.0.100-preview.4.26210.111: Fail (failed with System.TypeLoadException)
3). Windows 11 24H2 AMD64 + dotnet-sdk-11.0.100-preview.4.26214.103: Fail (failed with System.TypeLoadException)
4). Windows 11 24H2 AMD64 + dotnet-sdk-11.0.100-preview.4.26224.122: Fail (failed with Moq.MockException)

Known Workarounds

No response

Configuration

Application Name: GlobalToolsNETCore21Part02
OS: Windows 11 25H2
CPU: X64
.NET Build Number: dotnet-sdk-11.0.100-preview.4.26224.122

dotnet --info

.NET SDK:
Version: 11.0.100-preview.4.26224.122
Commit: 48bd87d899
Workload version: 11.0.100-manifests.e88583fc
MSBuild version: 18.7.0-preview-26224-122+48bd87d89

Runtime Environment:
OS Name: Windows
OS Version: 10.0.26100
OS Platform: Windows
RID: win-x64
Base Path: C:\Program Files\dotnet\sdk\11.0.100-preview.4.26224.122\

.NET workloads installed:
There are no installed workloads to display.
Configured to use workload sets when installing new manifests.
No workload sets are installed. Run "dotnet workload restore" to install a workload set.

Host:
Version: 11.0.0-preview.4.26224.122
Architecture: x64
Commit: 48bd87d899

.NET SDKs installed:
11.0.100-preview.4.26224.122 [C:\Program Files\dotnet\sdk]

.NET runtimes installed:
Microsoft.AspNetCore.App 11.0.0-preview.4.26224.122 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
Microsoft.NETCore.App 11.0.0-preview.4.26224.122 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
Microsoft.WindowsDesktop.App 11.0.0-preview.4.26224.122 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]

Other information

@dotnet-actwx-bot @dotnet/compat

[dotnet-policy-service]

Tagging subscribers to this area: @dotnet/area-extensions-logging
See info in area-owners.md if you want to be subscribed.

[MihuBot]

I'm a bot. Here is a possible related and/or duplicate issue (I may be wrong):

• TState in ILogger.Log<TState> used to be object, now FormattedLogValues extensions#1319

[WeiweiCaiAcpt]

@ericstj Could you please take a look at this bug? The previous System.TypeLoadException is no longer occurring, but a new Moq.MockException appears in the latest build (11.0.100-preview.4.26224.122).

Also, could you please confirm whether this is a blocker for .NET 11 P4 validation? Thanks.

[cincuranet]

AI Analysis

Context

This is the follow-up to #126995 (closed by PR #127194, which restored an obsolete shim Microsoft.Extensions.Logging.Internal.FormattedLogValues in Microsoft.Extensions.Logging.Abstractions). With that shim in place, the original TypeLoadException no longer occurs — the test app (docker-watch LoggerAdapterTest) now actually runs to the Verify step, where Moq reports the expected m.Log(...) call was never observed.

Root cause (this issue is not a runtime regression)

The test was authored against Microsoft.Extensions.Logging v2.x. Its mock setup looks like the well-known Moq pattern:

mockLogger.Verify(m => m.Log(
    LogLevel.Information,
    It.IsAny<EventId>(),
    It.IsAny<Microsoft.Extensions.Logging.Internal.FormattedLogValues>(),  // <- v2.x type
    null,
    It.IsAny<Func<Microsoft.Extensions.Logging.Internal.FormattedLogValues, Exception, string>>()));

ILogger.Log<TState> is a generic method. Each unique TState produces a distinct method instantiation at runtime, and Moq's Verify matches on that exact instantiation.

PR #127194 added Microsoft.Extensions.Logging.Internal.FormattedLogValues back as an [Obsolete(error: true)] [EditorBrowsable(Never)] shim — a different CLR type from the modern Microsoft.Extensions.Logging.FormattedLogValues that LoggerExtensions.LogInformation actually instantiates internally. So:

• The test's reference to the old type resolves (TypeLoadException gone ✅)
• But LoggerExtensions.LogInformation(...) calls logger.Log<Microsoft.Extensions.Logging.FormattedLogValues>(...) — the new namespace
• The mock was set up against logger.Log<Microsoft.Extensions.Logging.Internal.FormattedLogValues>(...)
• Different TState ⇒ different generic method instantiation ⇒ Moq sees zero matching invocations ⇒ MockException

This is the canonical "mocking ILogger is fragile" problem — exactly the topic linked by MihuBot: dotnet/extensions#1319. It's not unique to .NET 11; it's a long-standing consequence of FormattedLogValues having been internalized in 3.0 (and was the very reason to mark these obsolete shim types error: true in PR #127194).

Why the runtime can't round-trip this

Restoring the shim cannot make it bind-equivalent to the modern type:

• Two CLR types with the same simple name in different namespaces are always distinct identities.
• Generic instantiations are keyed by exact type identity; the JIT cannot "unify" …Internal.FormattedLogValues and …FormattedLogValues.
• Forcing LoggerExtensions to use the obsolete shim type internally would resurrect a public-but-obsolete type as a permanent ABI fixture in the modern code path — directly contradicting the intent of PR Add obsolete compatibility shims for moved Microsoft.Extensions.Logging internal types #127194 and the deprecation done years ago.

Recommendation

1. The test code pattern is the well-known Moq + ILogger anti-pattern. Recommended fix lives in test code, not the runtime.
2. Standard workaround: verify against It.IsAnyType and stop depending on the internal FormattedLogValues identity:

   mockLogger.Verify(l => l.Log(
       LogLevel.Information,
       It.IsAny<EventId>(),
       It.Is<It.IsAnyType>((v, t) => true),
       It.IsAny<Exception?>(),
       It.IsAny<Func<It.IsAnyType, Exception?, string>>()));

3. Better: use Microsoft.Extensions.Logging.Testing.FakeLogger (in Microsoft.Extensions.Diagnostics.Testing) instead of mocking ILogger.

[ericstj]

Agree with @cincuranet's analysis and recommendation. We can restore the old types, but we won't make the runtime use them, nor would we ever "promise" to keep that the same.

Also, could you please confirm whether this is a blocker for .NET 11 P4 validation? Thanks.

This is not a blocker.