The same object instance is used when running tests in parallel

[slapperywd]

I recently switched from MsTest to Unit3 and I noticed that when my tests are running in parallel I receive the same hashcode for an object set up in [SetUp] method.

using System;
using System.Threading;
using NUnit.Framework;
[assembly: Parallelizable(ParallelScope.All)]
namespace Nunit3netcore
{
    public class User
    {

    }
    public class Tests
    {
        public User User { get; set; }

        [SetUp]
        public void Setup()
        {
            User = new User();
        }

        [Test]
        public void Test1()
        {
            Thread.Sleep(3000);
            TestContext.WriteLine(User.GetHashCode());
        }

        [Test]
        public void Test2()
        {
            Thread.Sleep(3000);
            TestContext.WriteLine(User.GetHashCode());

        }

        [Test]
        public void Test5()
        {

            Thread.Sleep(3000);
            TestContext.WriteLine(User.GetHashCode());
        }
    }
}

In test output for each test, I see that the hash code is the same. When I comment out assembly:Parralilzable attribute and my code is running in non-paralell the hash code is different for each test. In MsTest I was generated a new object with new hash code within [TestInitialize] method. Packages I use: Nunit 3.12.0 Nunit3TestAdapter 3.16.1 Microsoft.NET.Test.Sdk (16.5.0)

[OsirisTerje]

@CharliePoole @jnm2 Any ideas ?

[CharliePoole]

Since @slapperywd doesn't show any override of GetHashCode(), I assume that the underlying System.Object.GetHashCode() is being used here. HashCodes are used by .NET as a preliminary test of equality and the way they work is that unequal codes guarantee inequality, while equal codes indicate that the two instances may be equal. Further value checks are usually needed.

The implementation of hash codes has changed with various versions of .NET. In this case, my guess is that it's getting some info for the hash from the executing thread itself. But, in any case, it isn't NUnit generating the hash codes.

In cases where you're concerned about the specifics of hash code generation for a particular Type, then you should be overriding GetHashCode().

[slapperywd]

@CharliePoole For each object instance (even there is no override of GetHashCode) .NET will generate unique hash code for an object. This is just simplified example and want to show that the same instance is used across all threads when I except different unique instance for one thread. The same code in MsTestv2 returned me different hash code

[slapperywd]

I actually faced the issue with my logger which does not write to appropriate test output. (This is simplified code, just to reproduce the issue I faced faster). It really breaks my tests because all logs are randomly messed up across all tests I am running.

using System;
using System.Collections.Generic;
using System.Threading;
using NUnit.Framework;
[assembly: Parallelizable(ParallelScope.All)]
namespace Nunit3netcore
{
    public interface ILogger
    {
        List<string> AllLogs { get; set; }
        void Log(string message);
    }

    public class NunitConsoleLogger : ILogger
    {
        public List<string> AllLogs { get; set; } = new List<string>();
        public void Log(string message)
        {
            AllLogs.Add(message);
        }
    }

    [Parallelizable(ParallelScope.All)]
    public class Tests
    {
        public ILogger Logger { get; set; }

        [SetUp]
        public void Setup()
        {
            Logger = new NunitConsoleLogger();
        }

        [Test]
        public void Test1()
        {
            Thread.Sleep(3000);
            Logger.Log($"{TestContext.CurrentContext.Test.Name}  {Logger.GetHashCode()}");
        }

        [Test]
        public void Test2()
        {
            Thread.Sleep(3000);
            Logger.Log($"{TestContext.CurrentContext.Test.Name}  {Logger.GetHashCode()}");

        }

        [Test]
        public void Test5()
        {

            Thread.Sleep(3000);
            Logger.Log($"{TestContext.CurrentContext.Test.Name}  {Logger.GetHashCode()}");
        }

        [TearDown]
        public void TearDown()
        {
            foreach (var log in Logger.AllLogs)
            {
                TestContext.WriteLine(log);
            }

        }
    }
}

In two words I have custom assertion library which implements Soft assert and it logs all errors in TearDown method and it does not log right. Below are tests outputs from each test Actual: Test1 output Standard Output: Test1 49538252 Test2 49538252

Test2 output Standard Output: Test1 49538252 Test2 49538252

Test3 output Standard Output: Test1 49538252 Test2 49538252

Expected Test1 output Standard Output: Test1 {somehash}

Test2 output Standard Output: Test2 {somehash}

Test3 output Standard Output: Test3 {somehash}

As you can see in Actual result the same hash code is generated and I assume this is why my logs are written incorrectly.

[CharliePoole]

@slapperywd "For each object instance (even there is no override of GetHashCode) .NET will generate unique hash code for an object." Sorry, but that's not correct.

From the Microsoft docs:

Two objects that are equal return hash codes that are equal. However, the reverse is not true: equal hash codes do not imply object equality, because different (unequal) objects can have identical hash codes. Furthermore, .NET does not guarantee the default implementation of the GetHashCode method, and the value this method returns may differ between .NET implementations, such as different versions of .NET Framework and .NET Core, and platforms, such as 32-bit and 64-bit platforms. For these reasons, do not use the default implementation of this method as a unique object identifier for hashing purposes. Two consequences follow from this:

• You should not assume that equal hash codes imply object equality.

• You should never persist or use a hash code outside the application domain in which it was created, because the same object may hash across application domains, processes, and platforms.

See also the "Warning" section in the above link.

It is true that hashes are sometimes (maybe even often) unique. I'm afraid you have just run into an example of non-uniqueness.

Also, as already answered, NUnit does nothing whatsoever to generate these hash codes. They are just part of the platform.

[CharliePoole]

Just noticed your title change... I'm very doubtful that the same object is used in each case, since you are creating separate objects.You can write a test to ensure that the same object instance is not being used. Just don't use hash code to do it.

Your latest code indicates you are displaying the hash code of the logger itself, not of the object under test. Is that your intention?

[slapperywd]

Sorry, I think that I confused you with this hash code example. The main issue in the example above is that I expect to see only one log record for each test but I am getting multiple. Actual: Test1 output Standard Output: Test1 Test2

Test2 output Standard Output: Test1 Test2

Test3 output Standard Output: Test1 49538252 Test2 49538252

Expected Test1 output Standard Output: Test1 {somehash}

Test2 output Standard Output: Test2

Test3 output Standard Output: Test3

In the Test1 I see logs from Test1 and Test2 for some reason. I just want to run all test methods in parallel and see only that logs which related to the specific test

[CharliePoole]

In that case, I'd suggest the problem isn't with the hash codes, but with the implementation of logging or how you are calling the logs. In the example, the calls seem straightforward, so I'd suspect the logger.

[slapperywd]

but in the example above I just declared a simple class which is initialized in SetUp method. The exactly the same behavior will output my logs to appropriate test case. It justs collects all logs into List and in TearDown method prints them all using TestContext.WriteLine. The simplest implementation , the same code works fine in MsTestv2. I do not understand why I observe the weird behavior in NUnit

[OsirisTerje]

This might be a problem in NUnit.Framework. I ran the repro above, and got this in the Test Explorer and command output: And the XML from the engine/framework show that the output from all tests are coming out with each test. That doesn't seem right:

Removing the parallel causes only one output for each (and also different hashcodes).

(I wouldn't care that much for now about the hashcode, I got them all equal, VS2019, net5, 3.13.2 and 4.0.0)

Repro code is here: https://github.com/nunit/nunit3-vs-adapter.issues/tree/master/Issue891

[OsirisTerje]

The logger is just the small class above. It doesn't contain anything suspicious. And the output from NUnit.Framework is on the other hand very suspicious. I think this issue should be transferred to the NUnit repro.

[slapperywd]

I tried also to downgrade my NUnit framework to a lower version (3.10.0) but it did not help. Would be very nice if it was fixed.

[CharliePoole]

@OsirisTerje Yes... I see that now... I was taking "logger" to be something more than that.

Still... the NUnit output is exactly what it should be for messages written to TestContext.WriteLine. Each test has a different TestContext, but all of them, even if parallel, share the same output destination.

Looking more closely, I think this example is falling afoul of a classic difference to other frameworks, which is a characteristic of NUnit. I'm annoyed I didn't see it right away.

The member property Logger is part of the test fixture state. In NUnit, as you know, fixture state is shared across all instances. One instance of the test fixture class is created for use by all of the test methods. We've discussed the reasons for this at incredible length elsewhere, so I won't go into it.

Based on experience with MsBuild, @slapperywd is probably expecting a fresh object instance for each test case, but he isn't getting it. When the tests are run in parallel, the setups and teardowns occur at random times with respect to one another. Each setup wipes out the previous collection and creates a new one. Each teardown writes out whatever is currently in the collection.

The simplest way to resolve this would be to stop saving the messages but write them out immediately. That gives NUnit the job of collecting them and associating them with each test.

In a broader context, this is why we generally advise people not to do logging from inside their tests but to do it in an engine extension. It's also one of many reasons I don't consider use of ParallelScope.All to be a very good practice, btw. :-)

[OsirisTerje]

@slapperywd So, the way to go is to use ParallelScope.Fixture, together with spreading the tests you want to run in parallel into separate fixtures. You can move your logger to a baseclass to not have to repeat that code. Also consider that the effect of parallel depends on the number of cores you have available, so you gain very little by having too much granularity. Fixture level should be more than enough.

[CharliePoole]

Good suggestions... Other ideas:

• Consider not using any global (assembly level) ParallelizableAttribute but instead placing them individually.

• Don't save your log messages in the fixture state, but write them immediately using TestContext. That way, it's NUnit's responsibility to handle the buffering and sort them out by class.

[slapperywd]

Thank you a lot guys for your suggestions. For me, it is very sad that I cannot parallel my tests on a test method level without having issues with context. Anyway, I did some research and my issue can be resolved using ThreadLocal but it looks more like a workaround to me. @OsirisTerje we do the same on our project using BaseClass where our Logger is placed, I just shared a dummy example for visibility. I created a repo where I created two classes https://github.com/slapperywd/Nunit3netcore/tree/master/Nunit3netcore UnitTest1 writes immediately to TestContext but you will have an issue writing all your logs to the file. Using ThreadLocal will resolve that issue represented in UnitTestWIthThreadLocal.cs. So, if I want to still have method level paralleziation and have no issues with my logging I should use ThreadLocal which guarantees that I will have a unique instance within a thread (what I actually need). Thank you guys for the answers again.

[rprouse]

When NUnit runs test in Parallel, it creates one instance of the test class and then calls each test method in parallel. So, what is happening is that Setup is being called multiple times creating and overwriting the User object then the tests all run using the last User created.

You can use thread local storage, or an easier fix is to add [FixtureLifeCycle(LifeCycle.InstancePerTestCase)] to the test class. If you do this, NUnit will create a new instance of your test class for each test method that is run.

See https://docs.nunit.org/articles/nunit/writing-tests/attributes/fixturelifecycle.html

[slapperywd]

@rprouse Awesome, works as I expected. Thank you a lot