Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Safer formatting of Xunit assertion messages #7446

Merged
merged 5 commits into from
Jan 8, 2025

Conversation

milang
Copy link
Contributor

@milang milang commented Jan 8, 2025

Fixes #7442

Changes

This pull request updates Akka.TestKit.XUnit2 to format assertion messages with string.Format only when formatting arguments are specified, otherwise it uses format string as-is. For more background/motivation, please see akkadotnet/Akka.TestKit.NUnit#159.

Additionally, this PR adds a new project, src/contrib/testkits/Akka.TestKit.Xunit2.Tests. This project contains tests that verify formatting behavior.

This PR also refactors the existing AkkaEqualException class. Instead of deferring assertion message creation/formatting until Message property call (as originally implemented), the updated code builds the message at the time exception instance is created, and stores the value in base class' Message property. This allows us to remove _format + _args fields and the Message property override, simplifying the class.

Please note that I also fixed the protected AkkaEqualException(SerializationInfo info, StreamingContext context) deserialization constructor that was implemented incorrectly + marked AkkaEqualException as [Serializable] + added a test AkkaEqualExceptionSpec.Constructor_deserializes_message to verify the serialization/deserialization roundtrip preserves the most important part of the exception instance, Message. I personally recommend removing the constructor altogether, as the base class XunitException does not implement deserialization constructor at all, plus the binary formatter is obsolete as of .NET 8+ (Microsoft announcement).

Important

@Aaronontheweb please let me know if you would like me to remove the constructor as part of this PR.

Checklist

For significant changes, please ensure that the following have been completed (delete if not relevant):

@milang milang force-pushed the safer-message-format branch from a141a33 to 208c05e Compare January 8, 2025 06:38
@biasc
Copy link

biasc commented Jan 8, 2025

Thanks @milang , I was about to create a PR but I saw that you had already done one.

@Aaronontheweb
Copy link
Member

@biasc @milang you guys are MVPs for submitting this - ty

@Aaronontheweb Aaronontheweb added the akka-testkit Akka.NET Testkit issues label Jan 8, 2025
@Aaronontheweb
Copy link
Member

Akka.Streams.Tests.Dsl.FlowSplitWhenSpec.SplitWhen_must_support_cancelling_substreams

Expected task to complete within 3s.

This is a racy spec - there's a bunch of timing-sensitive ones in the Akka.Streams test suite that have this problem. Issue is not caused by your PR

@Aaronontheweb
Copy link
Member

2025-01-08T09:10:28.0555582Z [xUnit.net 00:14:04.60]     Node 5 [node-5] [FAIL]
2025-01-08T09:10:28.0557425Z [xUnit.net 00:14:04.60]       Akka.TestKit.Xunit2.Internals.AkkaEqualException : Assert.Equal() Failure: 
2025-01-08T09:10:28.1617576Z [xUnit.net 00:14:04.60]       Stack Trace:
2025-01-08T09:10:28.2540108Z [xUnit.net 00:14:04.60]         D:\a\1\s\src\contrib\testkits\Akka.TestKit.Xunit2\XunitAssertions.cs(67,0): at Akka.TestKit.Xunit2.XunitAssertions.AssertEqual[T](T expected, T actual, String format, Object[] args)
2025-01-08T09:10:28.2955224Z [xUnit.net 00:14:04.60]       Output:
2025-01-08T09:10:28.3086275Z [xUnit.net 00:14:04.60]         Running specs for Akka.Cluster.Tests.MultiNode.dll [D:\a\1\s\src\core\Akka.Cluster.Tests.MultiNode\bin\Release\net8.0\Akka.Cluster.Tests.MultiNode.dll] 
2025-01-08T09:10:28.3562051Z [xUnit.net 00:14:04.60]         [INFO][01/08/2025 09:09:34.632Z][Thread 0001][remoting (akka://StressSpec)] Starting remoting
2025-01-08T09:10:28.3812348Z [xUnit.net 00:14:04.60]         [WARNING][01/08/2025 09:09:35.819Z][Thread 0024][FailureInjectorTransportAdapter (akka://StressSpec)] FailureInjectorTransport is active on this system. Gremlins might munch your packets.
2025-01-08T09:10:28.3832797Z [xUnit.net 00:14:04.60]         [INFO][01/08/2025 09:09:35.939Z][Thread 0001][remoting (akka://StressSpec)] Remoting started; listening on addresses : [akka.trttl.gremlin.tcp://StressSpec@localhost:55541]
2025-01-08T09:10:28.3837953Z [xUnit.net 00:14:04.60]         [INFO][01/08/2025 09:09:35.959Z][Thread 0001][Cluster (akka://StressSpec)] Cluster Node [akka.trttl.gremlin.tcp://StressSpec@localhost:55541] - Starting up...
2025-01-08T09:10:28.3840118Z [xUnit.net 00:14:04.60]         [INFO][01/08/2025 09:09:36.085Z][Thread 0015][Cluster (akka://StressSpec)] Cluster Node [akka.trttl.gremlin.tcp://StressSpec@localhost:55541] - No seed-nodes configured, manual cluster join required
2025-01-08T09:10:28.3841940Z [xUnit.net 00:14:04.60]         [INFO][01/08/2025 09:09:36.253Z][Thread 0001][Cluster (akka://StressSpec)] Cluster Node [akka.trttl.gremlin.tcp://StressSpec@localhost:55541] - Started up successfully
2025-01-08T09:10:28.3843602Z [xUnit.net 00:14:04.60]         [WARNING][01/08/2025 09:09:57.183Z][Thread 0015][akka.trttl.gremlin.tcp://StressSpec@localhost:55541/user/TestConductorClient] unhandled event <Terminated>: [akka://StressSpec/user/$a#1023069753] - ExistenceConfirmed=True in state Connected
2025-01-08T09:10:28.3845333Z [xUnit.net 00:14:04.60]         [INFO][01/08/2025 09:09:57.188Z][Thread 0001][StressSpec (akka://StressSpec)] Role [node-5] started with address [akka.trttl.gremlin.tcp://StressSpec@localhost:55541]
2025-01-08T09:10:28.3846744Z [xUnit.net 00:14:04.60]         [INFO][01/08/2025 09:09:57.244Z][Thread 0001][StressSpec (akka://StressSpec)] StressSpec CLR:
2025-01-08T09:10:28.3848079Z [xUnit.net 00:14:04.60]         Operating System: Win32NT, X64, Microsoft Windows NT 10.0.20348.0
2025-01-08T09:10:28.3849333Z [xUnit.net 00:14:04.60]         CLR: .NET 8.0.8
2025-01-08T09:10:28.3850527Z [xUnit.net 00:14:04.60]         Processors: 2
2025-01-08T09:10:28.3851736Z [xUnit.net 00:14:04.60]         Load average: can't be easily measured on .NET Core
2025-01-08T09:10:28.3852955Z [xUnit.net 00:14:04.60]         Thread count: 32
2025-01-08T09:10:28.3854870Z [xUnit.net 00:14:04.60]         Memory:  (82 - 83) MB [working set / peak working set]Args: 
2025-01-08T09:10:28.3856405Z [xUnit.net 00:14:04.60]         D:\a\1\s\src\core\Akka.Cluster.Tests.MultiNode\bin\Release\net8.0\Akka.MultiNode.RemoteHost.dll
2025-01-08T09:10:28.3857737Z [xUnit.net 00:14:04.60]         Akka.MultiNode.TestAdapter, Version=1.5.25.0, Culture=neutral, PublicKeyToken=null
2025-01-08T09:10:28.3858964Z [xUnit.net 00:14:04.60]         Akka.MultiNode.TestAdapter.NodeRunner.Executor
2025-01-08T09:10:28.3860154Z [xUnit.net 00:14:04.60]         Execute
2025-01-08T09:10:28.3861311Z [xUnit.net 00:14:04.60]         -Dmultinode.test-class="Akka.Cluster.Tests.MultiNode.StressSpec"
2025-01-08T09:10:28.3862510Z [xUnit.net 00:14:04.60]         -Dmultinode.test-method="Cluster_under_stress"
2025-01-08T09:10:28.3863655Z [xUnit.net 00:14:04.60]         -Dmultinode.max-nodes=13
2025-01-08T09:10:28.3864798Z [xUnit.net 00:14:04.60]         -Dmultinode.server-host="localhost"
2025-01-08T09:10:28.3865954Z [xUnit.net 00:14:04.60]         -Dmultinode.server-port=55522
2025-01-08T09:10:28.3867080Z [xUnit.net 00:14:04.60]         -Dmultinode.host="localhost"
2025-01-08T09:10:28.3868209Z [xUnit.net 00:14:04.60]         -Dmultinode.index=4
2025-01-08T09:10:28.3869405Z [xUnit.net 00:14:04.60]         -Dmultinode.role="node-5"
2025-01-08T09:10:28.3870786Z [xUnit.net 00:14:04.60]         -Dmultinode.listen-address=127.0.0.1
2025-01-08T09:10:28.3871962Z [xUnit.net 00:14:04.60]         -Dmultinode.listen-port=55521
2025-01-08T09:10:28.3873162Z [xUnit.net 00:14:04.60]         -Dmultinode.test-assembly="D:\a\1\s\src\core\Akka.Cluster.Tests.MultiNode\bin\Release\net8.0\Akka.Cluster.Tests.MultiNode.dll"
2025-01-08T09:10:28.3874136Z [xUnit.net 00:14:04.60]         
2025-01-08T09:10:28.3967244Z [xUnit.net 00:14:04.60]         [INFO][01/08/2025 09:10:03.259Z][Thread 0015][Cluster (akka://StressSpec)] Cluster Node [akka.trttl.gremlin.tcp://StressSpec@localhost:55541] - Welcome from [akka.trttl.gremlin.tcp://StressSpec@localhost:55545]
2025-01-08T09:10:28.3975644Z [xUnit.net 00:14:04.60]         [INFO][01/08/2025 09:10:04.090Z][Thread 0015][Cluster (akka://StressSpec)] Cluster Node [akka.trttl.gremlin.tcp://StressSpec@localhost:55541] - is the new leader among reachable nodes (more leaders may exist)
2025-01-08T09:10:28.3977476Z [xUnit.net 00:14:04.60]         [WARNING][01/08/2025 09:10:27.369Z][Thread 0004][ActorSystem(StressSpec)] AwaitAssert failed, timeout [00:00:29.8987450] is over after [269] attempts and [00:00:29.8989775] elapsed time
2025-01-08T09:10:28.3978570Z [xUnit.net 00:14:04.60]         ---------------DISPOSING--------------------
2025-01-08T09:10:28.3979838Z [xUnit.net 00:14:04.60]         [INFO][01/08/2025 09:10:27.375Z][Thread 0016][akka.trttl.gremlin.tcp://StressSpec@localhost:55541/user/TestConductorClient] Terminating connection to multi-node test controller due to [Akka.Actor.FSMBase+Shutdown]
2025-01-08T09:10:28.3980967Z [xUnit.net 00:14:04.60]         [INFO][01/08/2025 09:10:27.376Z][Thread 0028][PlayerHandler (akka://StressSpec)] Client: disconnecting [::1]:55555 from [::1]:55522
2025-01-08T09:10:28.3981947Z [xUnit.net 00:14:04.60]         [INFO][01/08/2025 09:10:27.382Z][Thread 0017][remoting-terminator] Shutting down remote daemon.
2025-01-08T09:10:28.3984840Z [xUnit.net 00:14:04.60]         [INFO][01/08/2025 09:10:27.384Z][Thread 0017][remoting-terminator] Remote daemon shut down; proceeding with flushing remote transports.
2025-01-08T09:10:28.3987369Z [xUnit.net 00:14:04.60]         [INFO][01/08/2025 09:10:27.406Z][Thread 0017][akka.trttl.gremlin.tcp://StressSpec@localhost:55541/system/endpointManager/reliableEndpointWriter-akka.trttl.gremlin.tcp%3A%2F%2FStressSpec%40localhost%3A55552-2] Removing receive buffers for [akka.trttl.gremlin.tcp://StressSpec@localhost:55541]->[akka.trttl.gremlin.tcp://StressSpec@localhost:55552]
2025-01-08T09:10:28.3989077Z [xUnit.net 00:14:04.60]         [INFO][01/08/2025 09:10:27.406Z][Thread 0018][akka.trttl.gremlin.tcp://StressSpec@localhost:55541/system/endpointManager/reliableEndpointWriter-akka.trttl.gremlin.tcp%3A%2F%2FStressSpec%40localhost%3A55546-4] Removing receive buffers for [akka.trttl.gremlin.tcp://StressSpec@localhost:55541]->[akka.trttl.gremlin.tcp://StressSpec@localhost:55546]
2025-01-08T09:10:28.3990765Z [xUnit.net 00:14:04.60]         [INFO][01/08/2025 09:10:27.406Z][Thread 0017][akka.trttl.gremlin.tcp://StressSpec@localhost:55541/system/endpointManager/reliableEndpointWriter-akka.trttl.gremlin.tcp%3A%2F%2FStressSpec%40localhost%3A55553-3] Removing receive buffers for [akka.trttl.gremlin.tcp://StressSpec@localhost:55541]->[akka.trttl.gremlin.tcp://StressSpec@localhost:55553]
2025-01-08T09:10:28.3993220Z [xUnit.net 00:14:04.60]         [INFO][01/08/2025 09:10:27.406Z][Thread 0017][akka.trttl.gremlin.tcp://StressSpec@localhost:55541/system/endpointManager/reliableEndpointWriter-akka.trttl.gremlin.tcp%3A%2F%2FStressSpec%40localhost%3A55545-1] Removing receive buffers for [akka.trttl.gremlin.tcp://StressSpec@localhost:55541]->[akka.trttl.gremlin.tcp://StressSpec@localhost:55545]
2025-01-08T09:10:28.3998684Z [xUnit.net 00:14:04.60]         [INFO][01/08/2025 09:10:27.489Z][Thread 0017][remoting-terminator] Remoting shut down.
2025-01-08T09:10:28.4000239Z [xUnit.net 00:14:04.60]         
2025-01-08T09:10:28.4001172Z [xUnit.net 00:14:04.60]         [Node5:node-5][FAIL] Akka.Cluster.Tests.MultiNode.StressSpec.Cluster_under_stress
2025-01-08T09:10:28.4002144Z [xUnit.net 00:14:04.60]         [Node5:node-5][FAIL-EXCEPTION] Type: Akka.TestKit.Xunit2.Internals.AkkaEqualException
2025-01-08T09:10:28.4003099Z [xUnit.net 00:14:04.60]         --> [Node5:node-5][FAIL-EXCEPTION] Message: Assert.Equal() Failure: 
2025-01-08T09:10:28.4003989Z [xUnit.net 00:14:04.60]         Expected: 5
2025-01-08T09:10:28.4013102Z [xUnit.net 00:14:04.60]         Actual:   4
2025-01-08T09:10:28.4014568Z [xUnit.net 00:14:04.60]         --> [Node5:node-5][FAIL-EXCEPTION] StackTrace:    at Akka.TestKit.Xunit2.XunitAssertions.AssertEqual[T](T expected, T actual, String format, Object[] args) in D:\a\1\s\src\contrib\testkits\Akka.TestKit.Xunit2\XunitAssertions.cs:line 67
2025-01-08T09:10:28.4016066Z [xUnit.net 00:14:04.60]            at Akka.Cluster.TestKit.MultiNodeClusterSpec.<>c__DisplayClass28_0.<AwaitMembersUp>b__2() in D:\a\1\s\src\core\Akka.Cluster.TestKit\MultiNodeClusterSpec.cs:line 374
2025-01-08T09:10:28.4023101Z [xUnit.net 00:14:04.60]            at Akka.TestKit.TestKitBase.AwaitAssertAsync(Action assertion, Nullable`1 duration, Nullable`1 interval, CancellationToken cancellationToken) in D:\a\1\s\src\core\Akka.TestKit\TestKitBase_AwaitAssert.cs:line 60
2025-01-08T09:10:28.4024396Z [xUnit.net 00:14:04.60]            at Nito.AsyncEx.Synchronous.TaskExtensions.WaitAndUnwrapException(Task task)
2025-01-08T09:10:28.4025456Z [xUnit.net 00:14:04.60]            at Akka.TestKit.TestKitBase.AwaitAssert(Action assertion, Nullable`1 duration, Nullable`1 interval, CancellationToken cancellationToken) in D:\a\1\s\src\core\Akka.TestKit\TestKitBase_AwaitAssert.cs:line 39
2025-01-08T09:10:28.4026689Z [xUnit.net 00:14:04.60]            at Akka.Cluster.TestKit.MultiNodeClusterSpec.<>c__DisplayClass28_0.<AwaitMembersUp>b__0() in D:\a\1\s\src\core\Akka.Cluster.TestKit\MultiNodeClusterSpec.cs:line 374
2025-01-08T09:10:28.4027745Z [xUnit.net 00:14:04.60]            at Akka.TestKit.TestKitBase.<>c__DisplayClass216_0.<Within>b__0() in D:\a\1\s\src\core\Akka.TestKit\TestKitBase_Within.cs:line 44
2025-01-08T09:10:28.4028848Z [xUnit.net 00:14:04.60]            at Akka.TestKit.TestKitBase.WithinAsync[T](TimeSpan min, TimeSpan max, Func`1 function, String hint, Nullable`1 epsilonValue, CancellationToken cancellationToken) in D:\a\1\s\src\core\Akka.TestKit\TestKitBase_Within.cs:line 278
2025-01-08T09:10:28.4030067Z [xUnit.net 00:14:04.60]            at Akka.TestKit.TestKitBase.Within(TimeSpan max, Action action, Nullable`1 epsilonValue, CancellationToken cancellationToken) in D:\a\1\s\src\core\Akka.TestKit\TestKitBase_Within.cs:line 39
2025-01-08T09:10:28.4031230Z [xUnit.net 00:14:04.60]            at Akka.Cluster.TestKit.MultiNodeClusterSpec.AwaitMembersUp(Int32 numbersOfMembers, ImmutableHashSet`1 canNotBePartOfMemberRing, Nullable`1 timeout) in D:\a\1\s\src\core\Akka.Cluster.TestKit\MultiNodeClusterSpec.cs:line 366
2025-01-08T09:10:28.4032486Z [xUnit.net 00:14:04.60]            at Akka.Cluster.Tests.MultiNode.StressSpec.<>c__DisplayClass43_0.<MustJoinSeedNodes>b__2() in D:\a\1\s\src\core\Akka.Cluster.Tests.MultiNode\StressSpec.cs:line 1318
2025-01-08T09:10:28.4033557Z [xUnit.net 00:14:04.60]            at Akka.Cluster.Tests.MultiNode.StressSpec.ReportResult[T](Func`1 thunk) in D:\a\1\s\src\core\Akka.Cluster.Tests.MultiNode\StressSpec.cs:line 1133
2025-01-08T09:10:28.4034667Z [xUnit.net 00:14:04.60]            at Akka.Cluster.Tests.MultiNode.StressSpec.<>c__DisplayClass43_0.<MustJoinSeedNodes>b__1() in D:\a\1\s\src\core\Akka.Cluster.Tests.MultiNode\StressSpec.cs:line 1315
2025-01-08T09:10:28.4035704Z [xUnit.net 00:14:04.60]            at Akka.Remote.TestKit.MultiNodeSpec.RunOn(Action thunk, RoleName[] nodes) in D:\a\1\s\src\core\Akka.Remote.TestKit\MultiNodeSpec.cs:line 526
2025-01-08T09:10:28.4036720Z [xUnit.net 00:14:04.60]            at Akka.Cluster.Tests.MultiNode.StressSpec.<MustJoinSeedNodes>b__43_0() in D:\a\1\s\src\core\Akka.Cluster.Tests.MultiNode\StressSpec.cs:line 1313
2025-01-08T09:10:28.4037739Z [xUnit.net 00:14:04.60]            at Akka.TestKit.TestKitBase.<>c__DisplayClass216_0.<Within>b__0() in D:\a\1\s\src\core\Akka.TestKit\TestKitBase_Within.cs:line 44
2025-01-08T09:10:28.4038809Z [xUnit.net 00:14:04.60]            at Akka.TestKit.TestKitBase.WithinAsync[T](TimeSpan min, TimeSpan max, Func`1 function, String hint, Nullable`1 epsilonValue, CancellationToken cancellationToken) in D:\a\1\s\src\core\Akka.TestKit\TestKitBase_Within.cs:line 278
2025-01-08T09:10:28.4040001Z [xUnit.net 00:14:04.60]            at Akka.TestKit.TestKitBase.Within(TimeSpan max, Action action, Nullable`1 epsilonValue, CancellationToken cancellationToken) in D:\a\1\s\src\core\Akka.TestKit\TestKitBase_Within.cs:line 39
2025-01-08T09:10:28.4041193Z [xUnit.net 00:14:04.60]            at Akka.Cluster.Tests.MultiNode.StressSpec.MustJoinSeedNodes() in D:\a\1\s\src\core\Akka.Cluster.Tests.MultiNode\StressSpec.cs:line 1305
2025-01-08T09:10:28.4042220Z [xUnit.net 00:14:04.60]            at Akka.Cluster.Tests.MultiNode.StressSpec.Cluster_under_stress() in D:\a\1\s\src\core\Akka.Cluster.Tests.MultiNode\StressSpec.cs:line 1259
2025-01-08T09:10:28.4043186Z [xUnit.net 00:14:04.60]            at System.RuntimeMethodHandle.InvokeMethod(Object target, Void** arguments, Signature sig, Boolean isConstructor)
2025-01-08T09:10:28.4044188Z [xUnit.net 00:14:04.60]            at System.Reflection.MethodBaseInvoker.InvokeWithNoArgs(Object obj, BindingFlags invokeAttr)
2025-01-08T09:10:28.4044998Z [xUnit.net 00:14:04.60]         

I'll need to re-run this and see what's going on here - test didn't get "reported" as failed by AzDo for some reason, but I could find this in the logs.

@milang
Copy link
Contributor Author

milang commented Jan 8, 2025

@Aaronontheweb

I'll need to re-run this and see what's going on here - test didn't get "reported" as failed by AzDo for some reason, but I could find this in the logs.

I removed serialization from AkkaEqualException to see how it affects tests. If you want to keep serialization, I can easily remove the commit from my branch.

@Aaronontheweb
Copy link
Member

@Aaronontheweb

I'll need to re-run this and see what's going on here - test didn't get "reported" as failed by AzDo for some reason, but I could find this in the logs.

I removed serialization from AkkaEqualException to see how it affects tests. If you want to keep serialization, I can easily remove the commit from my branch.

Let's go ahead and keep it just because I don't know what the secondary effects are of removing it

@milang milang force-pushed the safer-message-format branch from f213199 to e93440b Compare January 8, 2025 21:11
@milang
Copy link
Contributor Author

milang commented Jan 8, 2025

@Aaronontheweb

Let's go ahead and keep it just because I don't know what the secondary effects are of removing it

I restored the AkkaEqualException serialization and rebased on the latest dev branch.

@Aaronontheweb Aaronontheweb merged commit 26383ec into akkadotnet:dev Jan 8, 2025
8 of 11 checks passed
@Aaronontheweb
Copy link
Member

Thank you @milang !

@milang milang deleted the safer-message-format branch January 8, 2025 22:49
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
akka-testkit Akka.NET Testkit issues
Projects
None yet
Development

Successfully merging this pull request may close these issues.

ExpectMsgFromAsync throws Format Excepion
3 participants