Getting sequential logs while executing tests in parallel

Question

We have been using testng with java to execute integration tests for our code. We have implemented a listener for the test execution as follows :-

public class TestExecutionListener implements IInvokedMethodListener {

    @Override
    public void beforeInvocation(IInvokedMethod iInvokedMethod, ITestResult iTestResult) {
        System.out.println("Testing : " + iInvokedMethod.getTestMethod().getMethodName());
    }

    @Override
    public void afterInvocation(IInvokedMethod iInvokedMethod, ITestResult iTestResult) {
        System.out.println("Successfully Tested : " + iInvokedMethod.getTestMethod().getMethodName());
    }
}

Our testng.xml is defined as :-

<!DOCTYPE suite SYSTEM "http://testng.org/testng-1.0.dtd" >

<suite name="TestSuite" verbose="1" parallel="classes" thread-count="10">
    <listeners>
        <listener class-name="core.TestExecutionListener"/>
    </listeners>

    <test name="IntegrationTests">
        <classes>
            <class name="test.SomeTest1"/>
            <class name="test.SomeTest2"/>
            <class name="test.SomeTest3"/>
            <class name="test.SomeTest4"/>
            ... There are more than 20 classes
        </classes>
    </test>
</suite>

As we execute the tests, the output that we get is as follows :

Testing : SomeTest1Method1
Testing : SomeTest2Method2
Testing : SomeTest4Method5
Successfully Tested : SomeTest2Method2
Successfully Tested : SomeTest4Method5

while what we would be expecting the output to be is:-

Testing : SomeTest1Method1
Successfully Tested : SomeTest1Method1
Testing : SomeTest2Method2
Successfully Tested : SomeTest2Method2
Testing : SomeTest4Method5
Successfully Tested : SomeTest4Method5

Guessing this to because of the parallel="classes" attribute in the xml, since changing it to false provides the desired output. But as obvious the changed execution consumes a lot more time as compared to parallel execution.

Is there a way to run these tests in parallel but still get this output in sequence?

Answer 1

When you enable parallel then there will be some time between the beforeInvocation and afterInvocation in the logs as you have noticed and that difference in time varies from test to test hence the staggered output.

If what you want is the start and end messages next to each other then you are basically throwing out the time factor and as such can simply add your beforeInvocation message to the afterInvocation method as follows:

public class TestExecutionListener implements IInvokedMethodListener {

    @Override
    public void beforeInvocation(IInvokedMethod iInvokedMethod, ITestResult iTestResult) {
    }

    @Override
    public void afterInvocation(IInvokedMethod iInvokedMethod, ITestResult iTestResult) {
        System.out.println("Testing : " + iInvokedMethod.getTestMethod().getMethodName());
        System.out.println("Successfully Tested : " + iInvokedMethod.getTestMethod().getMethodName());
    }
}

IMO this is the only way to do it as per your spec. However, if there is other information that must be gathered during the tests then perhaps you could buffer some logs in the TestExecutionListener for example:

public class TestExecutionListener implements IInvokedMethodListener {
    private Map<Integer, Deque<String>> logsMap = new HashMap<Integer, Deque<String>>();

    public void log(IInvokedMethod iInvokedMethod, String log) {
        if(!logsMap.containsKey(iInvokedMethod.getId())) {
            logsMap.put(iInvokedMethod.getId(), new ArrayDeque<String>());
        }

        logsMap.get(iInvokedMethod.getId()).add(log);
    }

    @Override
    public void beforeInvocation(IInvokedMethod iInvokedMethod, ITestResult iTestResult) {
        log(iInvokedMethod, "Testing : " + iInvokedMethod.getTestMethod().getMethodName());
    }

    @Override
    public void afterInvocation(IInvokedMethod iInvokedMethod, ITestResult iTestResult) {
        log(iInvokedMethod, "Successfully Tested : " + iInvokedMethod.getTestMethod().getMethodName());

        Deque<String> logs = logsMap.get(iInvokedMethod.getId());
        while(!logs.isEmpty()) {
            System.out.println(logs.poll());
        }
    }
}