@BeforeClass extra invocation before @Test

[IZaiarnyi]

testng.zip

TestNG Version

6.10 6.11

Expected behavior

TestNG-test=All tests-2 baseTest @BeforeClass
TestNG-test=All tests-2 test2 @BeforeClass
TestNG-test=All tests-1 baseTest @BeforeClass
TestNG-test=All tests-1 test1 @BeforeClass
TestNG-test=All tests-2 test2.1 @Test
TestNG-test=All tests-1 test1.1 @Test
TestNG-test=All tests-2 test2.2 @Test
TestNG-test=All tests-1 test1.2 @Test
TestNG-test=All tests-2 baseTest @AfterClass
TestNG-test=All tests-1 baseTest @AfterClass

Actual behavior

TestNG-test=All tests-2 baseTest @BeforeClass
TestNG-test=All tests-2 test2 @BeforeClass
TestNG-test=All tests-1 baseTest @BeforeClass
TestNG-test=All tests-1 test1 @BeforeClass
TestNG-test=All tests-2 test2.1 @Test
TestNG-test=All tests-1 test1.1 @Test
TestNG-test=All tests-2 baseTest @BeforeClass
TestNG-test=All tests-2 test2 @BeforeClass
TestNG-test=All tests-2 test2.2 @Test
TestNG-test=All tests-1 test1.2 @Test
TestNG-test=All tests-2 baseTest @AfterClass
TestNG-test=All tests-1 baseTest @AfterClass

Is the issue reproductible on runner?

• [ ] Shell
• [X] Maven
• [ ] Gradle
• [ ] Ant
• [ ] Eclipse
• [X] IntelliJ
• [ ] NetBeans

Test case sample

1. Run test.xml from attachment above
2. Check output.

Additional information

BaseTest: contains @BeforeClass, @AfterClass
Test1: contains @BeforeClass, 2@Test extends BaseTest
Test2: contains @BeforeClass, 2@Test extends BaseTest

It reproduces in ~5% cases

[ebookerd1]

I experience this issue 100% of the time in a test that contains multiple test in a class that are dependent on each other. Currently using 6.11 and 6.13

[krmahadevan]

@ebookerd1 - Can you please confirm if using the attached example in this bug but with TestNG 6.13.1 you are still able to reproduce this issue ? If not, please help provide a sample that can be used to reproduce this issue.

[ebookerd1]

I am able to reproduce 100% when a test uses the "dependsOnMethod" the using 6.13.1 @Test(dependsOnMethods = { "previoustest" })

[ebookerd1]

I haven't had a chance to test this with groups but I didn't notices it with my tests.

[krmahadevan]

I am not able to reproduce this using the latest released version 6.14.3 Please feel free to share a reproducible sample, if this is still a problem with 6.14.3

Here's what I have used to try reproducing this.

Test classes

import org.testng.annotations.AfterClass;
import org.testng.annotations.BeforeClass;

public class BaseTest {
    static String getThreadInfo() {
        return " running on thread [" + Thread.currentThread().getId() + "]";
    }

    @BeforeClass
    public void baseTestBeforeClass() {
        System.err.println(getClass().getName() + ".baseTestBeforeClass() " + getThreadInfo());
    }

    @AfterClass
    public void baseTestAfterClass() {
        System.err.println(getClass().getName() + ".baseTestAfterClass() " + getThreadInfo());
    }
}

import org.testng.annotations.BeforeClass;
import org.testng.annotations.Test;

public class Test1 extends BaseTest {

    @BeforeClass
    public void testBeforeClass() {
        System.err.println(getClass().getName() + ".testBeforeClass() " + getThreadInfo());
    }

    @Test
    public  void test1() {
        System.err.println(getClass().getName() + ".test1() " + getThreadInfo());
    }
    @Test
    public  void test2() {
        System.err.println(getClass().getName() + ".test2() " + getThreadInfo());
    }
}

import org.testng.annotations.BeforeClass;
import org.testng.annotations.Test;

public class Test2 extends BaseTest {

    @BeforeClass
    public void testBeforeClass() {
        System.err.println(getClass().getName() + ".testBeforeClass() " + getThreadInfo());
    }
    @Test
    public  void test1() {
        System.err.println(getClass().getName() + ".test1() " + getThreadInfo());
    }

    @Test
    public  void test2() {
        System.err.println(getClass().getName() + ".test2() " + getThreadInfo());
    }
}

Test case that shows that this works fine

import org.assertj.core.api.Assertions;
import org.testng.*;
import org.testng.annotations.Test;
import org.testng.xml.XmlClass;
import org.testng.xml.XmlSuite;
import org.testng.xml.XmlTest;

import java.util.Arrays;
import java.util.Collections;
import java.util.Set;
import java.util.concurrent.ConcurrentHashMap;

public class SimulateError {
    @Test
    public void testMethod() {
        Set<String> iteration1 = runTests(XmlSuite.ParallelMode.CLASSES);
        Set<String> iteration2 = runTests(XmlSuite.ParallelMode.NONE);
        Assertions.assertThat(iteration1).containsAll(iteration2);
    }

    private static Set<String> runTests(XmlSuite.ParallelMode mode) {
        XmlSuite suite = createXmlSuite();
        createXmlTest(suite, Test1.class, Test2.class);
        suite.setParallel(mode);
        System.err.println("Suite xml is as below \n " + suite.toXml() + "\n");
        TestNG tng = create(mode);
        GatherOutput listener = new GatherOutput();
        tng.addListener((ITestNGListener) listener);
        tng.run();
        return listener.getLogs();
    }

    private static XmlSuite createXmlSuite() {
        XmlSuite result = new XmlSuite();
        result.setName("suite");
        return result;
    }

    private static void createXmlTest(XmlSuite suite, Class<?>... classes) {
        XmlTest result = new XmlTest(suite);
        result.setName("test");
        Arrays.stream(classes)
                .forEach(c -> result.getXmlClasses().add(new XmlClass(c.getName(), true)));
    }

    private static TestNG create(XmlSuite.ParallelMode mode) {
        XmlSuite suite = createXmlSuite();
        createXmlTest(suite, Test1.class, Test2.class);
        suite.setParallel(mode);
        TestNG result = new TestNG();
        result.setUseDefaultListeners(false);
        result.setVerbose(2);
        result.setXmlSuites(Collections.singletonList(suite));
        return result;
    }

    public static class GatherOutput implements IInvokedMethodListener {
        private Set<String> logs = ConcurrentHashMap.newKeySet();

        @Override
        public void beforeInvocation(IInvokedMethod method, ITestResult testResult) {
        }

        @Override
        public void afterInvocation(IInvokedMethod method, ITestResult testResult) {
            logs.addAll(Reporter.getOutput(testResult));
        }

        public Set<String> getLogs() {
            return logs;
        }
    }
}

Console output

Suite xml is as below 
 <?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE suite SYSTEM "http://testng.org/testng-1.0.dtd">
<suite name="suite" parallel="classes">
  <test thread-count="5" name="test" parallel="classes">
    <classes>
      <class name="rationale.emotions.issue1607.Test1"/>
      <class name="rationale.emotions.issue1607.Test2"/>
    </classes>
  </test> <!-- test -->
</suite> <!-- suite -->

rationale.emotions.issue1607.Test1.baseTestBeforeClass()  running on thread [11]
rationale.emotions.issue1607.Test2.baseTestBeforeClass()  running on thread [12]
rationale.emotions.issue1607.Test1.testBeforeClass()  running on thread [11]
rationale.emotions.issue1607.Test2.testBeforeClass()  running on thread [12]
rationale.emotions.issue1607.Test1.test1()  running on thread [11]
rationale.emotions.issue1607.Test2.test1()  running on thread [12]
rationale.emotions.issue1607.Test2.test2()  running on thread [12]
rationale.emotions.issue1607.Test1.test2()  running on thread [11]
rationale.emotions.issue1607.Test2.baseTestAfterClass()  running on thread [12]
rationale.emotions.issue1607.Test1.baseTestAfterClass()  running on thread [11]

===============================================
suite
Total tests run: 4, Failures: 0, Skips: 0
===============================================

Suite xml is as below 
 <?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE suite SYSTEM "http://testng.org/testng-1.0.dtd">
<suite name="suite">
  <test thread-count="5" name="test">
    <classes>
      <class name="rationale.emotions.issue1607.Test1"/>
      <class name="rationale.emotions.issue1607.Test2"/>
    </classes>
  </test> <!-- test -->
</suite> <!-- suite -->

rationale.emotions.issue1607.Test1.baseTestBeforeClass()  running on thread [1]
rationale.emotions.issue1607.Test1.testBeforeClass()  running on thread [1]
rationale.emotions.issue1607.Test1.test1()  running on thread [1]
rationale.emotions.issue1607.Test1.test2()  running on thread [1]
rationale.emotions.issue1607.Test1.baseTestAfterClass()  running on thread [1]
rationale.emotions.issue1607.Test2.baseTestBeforeClass()  running on thread [1]
rationale.emotions.issue1607.Test2.testBeforeClass()  running on thread [1]
rationale.emotions.issue1607.Test2.test1()  running on thread [1]
rationale.emotions.issue1607.Test2.test2()  running on thread [1]
rationale.emotions.issue1607.Test2.baseTestAfterClass()  running on thread [1]

===============================================
suite
Total tests run: 4, Failures: 0, Skips: 0
===============================================

[IZaiarnyi]

Hi Krishnan. This bug still reproduces on version TestNG 6.14.3

I had run SimulateError in your example with invocationCount=1000 and everything was green. But in console output I found this bug in many tests.

Should I create new issue?

[krmahadevan]

@IZaiarnyi - I would prefer that we dont create a new issue and use this one itself. Can you please help modify the sample that I had shared, so that I can use it to reproduce the problem ? Its hard to basically look at console output and predict if something is working fine or not. So please feel to alter the sample that I shared and add required assertions that shows the test fails.

What are you using to show the logs on the console ? Are you using System.out.println or are you using a Logger ?

[IZaiarnyi]

I just used your example with System.err.println. I'll try to modify your sample to catch the bug by assert.

[IZaiarnyi]

The problem was in Reporter.getOutput(testResult) it always returns empty List. I made some changes to fix it.

import org.assertj.core.api.Assertions;
import org.testng.*;
import org.testng.annotations.Test;
import org.testng.xml.XmlClass;
import org.testng.xml.XmlSuite;
import org.testng.xml.XmlTest;

import java.util.*;
import java.util.concurrent.ConcurrentHashMap;

public class SimulateError {

    @Test(invocationCount = 100)
    public void testMethod() {
        List<String> iteration1 = runTests(XmlSuite.ParallelMode.CLASSES);
        List<String> iteration2 = runTests(XmlSuite.ParallelMode.NONE);
        Assertions.assertThat(iteration1)
                .containsExactlyInAnyOrder((String[]) iteration2.toArray(new String[0]));
    }

    private static List<String> runTests(XmlSuite.ParallelMode mode) {
        XmlSuite suite = createXmlSuite();
        createXmlTest(suite, Test1.class, Test2.class);
        suite.setParallel(mode);
        System.err.println("Suite xml is as below \n " + suite.toXml() + "\n");
        TestNG tng = create(mode);
        GatherOutput listener = new GatherOutput();
        tng.addListener((ITestNGListener) listener);
        tng.run();
        return listener.getInvocationMethodsNames();
    }

    private static XmlSuite createXmlSuite() {
        XmlSuite result = new XmlSuite();
        result.setName("suite");
        return result;
    }

    private static void createXmlTest(XmlSuite suite, Class<?>... classes) {
        XmlTest result = new XmlTest(suite);
        result.setName("test");
        Arrays.stream(classes)
                .forEach(c -> result.getXmlClasses().add(new XmlClass(c.getName(), true)));
    }

    private static TestNG create(XmlSuite.ParallelMode mode) {
        XmlSuite suite = createXmlSuite();
        createXmlTest(suite, Test1.class, Test2.class);
        suite.setParallel(mode);
        TestNG result = new TestNG();
        result.setUseDefaultListeners(false);
        result.setVerbose(2);
        result.setXmlSuites(Collections.singletonList(suite));
        return result;
    }

    public static class GatherOutput implements IInvokedMethodListener {
        private Set<String> logs = ConcurrentHashMap.newKeySet();
        private List<String> testNames = Collections.synchronizedList(new ArrayList<>());

        @Override
        public void beforeInvocation(IInvokedMethod method, ITestResult testResult) {
        }

        @Override
        public void afterInvocation(IInvokedMethod method, ITestResult testResult) {
            logs.addAll(Reporter.getOutput(testResult));
            testNames.add(testResult.getMethod().getMethodName());
        }

        public Set<String> getLogs() {
            return logs;
        }

        public List<String> getInvocationMethodsNames() {
            return testNames;
        }
    }
}

[krmahadevan]

@IZaiarnyi I ran the sample that you shared. It runs fine. Does it mean that we can have this issue closed ?

[IZaiarnyi]

I don't think so. Did you run it with @Test(invocationCount = 100)? Did you run it on Mac?

We went little bit deeper and test was run several times with invocationCount = 10000 on different machine and OS.

Average number of failed tests on OS:

• Win10 = ~200
• xubuntu16.04 = ~30
• Mac OS X 10.13.4 = 0

As you see the issue is more common for WIn10 . You can use it or other WIn for reproducing this issue.

[krmahadevan]

@IZaiarnyi I ran the test that you shared in this comment. And yes I am running on Mac.

As you see the issue is more common for WIn10 . You can use it or other WIn for reproducing this issue.

I would be curious to know how do you expect a fix to be done that is depending on an Operating system? That is beyond the scope of what TestNG can do no? So without some help in reproducing this issue, I am not sure, what I can do to help here. So maybe I would side step and let someone else pitch in here for help.

[krmahadevan]

@juherr @cbeust Please advise.

[juherr]

It's not clear to me what is the issue. parallel run and/or reporter?

[IZaiarnyi]

@juherr Extra(incorrect/unexpected) invocations of @BeforeClass are appeared in parallel run for Windows and Linux.

[krmahadevan]

@IZaiarnyi - Just to clear out the ambiguities... Are you sure that you are using the same JDK flavor and version across all the platforms ? If not, then you should and report back.. The fact that the TestNG code works fine on one platform and not on another platform suggests, that this perhaps is not a TestNG issue after all... but could be related to how threading is implemented in the JDK flavor for the given platform.

[juherr]

It could be a jre issue but maybe we can find a workaround if we are able to find to root cause.

[IZaiarnyi]

Yep I used oracle jdk 1.8.0_162 x64 for investigation this issue across all the platforms.

But it's not a matter of jdk version because we have this problem on a different versions.

The sample is attached below:

testngBug.zip

One thing I can say for sure that percentage of failed tests on unix based system is less than on Windows. May be for Mac we need to increase invocation count and issue will be reproducible.

[krmahadevan]

@juherr

It could be a jre issue but maybe we can find a workaround if we are able to find to root cause.

Wouldn't that be equivalent to us trying to optimize for a particular JRE flavor ? Just asking.

@IZaiarnyi

May be for Mac we need to increase invocation count and issue will be reproducible.

Sure could be. And that is where we are asking you for your help, to help share as much information as you possibly can, so that we can get it fixed. Right now there are too many unknowns.

[juherr]

@krmahadevan Exactly and it could be time-consuming. But it could explain the random failing tests on Travis too.

[IZaiarnyi]

I asked a few persons to help me verify this issue on Mac. They weren't able to reproduce it. So we can assume that on Mac everything is OK.

The people who helped me to check it on other OSs, were able to reproduce it in 100% cases with sample above.

[krmahadevan]

Ok. In that case, let me see if I can reproduce this issue on a Ubuntu VM and also on a Windows VM and post back my findings. I only have access to VMs that are running on my Mac. Not sure if that is going to be relevant here. But still thought about calling this out.