Thread ID changes between test and *Invocation events when the test timeout set

[jcdkount]

Using the attached code, run the Bug.xml file.

EXPECTED: beforeInvocation, afterInvocation should always be on the same thread as the test.

ACTUAL: When you change the timeout in the annotation transformer (IAnnotationTransformer), the before and after Invocation events are on a different thread.

NOTE: In testing, I noticed that if I set the timeout by the @test annotation, it also has the same problem, but I suspect it happening at run time might make this harder to patch, so I left in the more complex case.

Example output:

beforeInvocation ; Expected SAME Thread: 11 - pool-1-thread-1
myExampleTest ; Expected SAME Thread: 12 - TestNGInvoker-myExampleTest()
afterInvocation ; Expected SAME Thread: 11 - pool-1-thread-1

Possible ways to fix this:

• Make the thread the same even if the timeout changes.
• ITestResult or IInvokedMethod include the thread id or Thread object which is stored when the the test method is executed.

For further detail on the discussion of this issue, see https://groups.google.com/forum/#!topic/testng-users/W3lQsykKa3w

Bug.zip

[juherr]

Related to #599

[cbeust]

The reason for this is that when you set a time out on a test method, that method gets run on a one-off executor so that the time out can be applied on it.

I once looked into fixing this but this changehas a lot of deep reaching consequences that I don't really have a clear resolution for.

[ricardf-cmp]

Glad to know there's an open issue for this! This is currently messing up with my logging (log4j). Is there any place where I can do some code before the test starts? Somewhat like "beforeInvocationInsideTestNGInvoker"?

[ricardf-cmp]

I've done a bit of research. I saw that on some comment you said that not using a new thread for each test run when there's a timeout would be a problem (I don't know why but hey you're the expert). What I don't get is why are you not calling the "run" method of an IHookable if there's a timeout also.

https://github.com/cbeust/testng/blob/testng-6.9.5/src/main/java/org/testng/internal/Invoker.java#L635

Does the timeout protection break SO much the whole thing?

[juherr]

not using a new thread for each test run when there's a timeout would be a problem (I don't know why but hey you're the expert)

Because timeout is managed by a executor which is a simple way to manage timeout. But we are open to another solution.

What I don't get is why are you not calling the "run" method of an IHookable if there's a timeout also.

It is: https://github.com/cbeust/testng/blob/testng-6.9.5/src/main/java/org/testng/internal/MethodInvocationHelper.java#L208

[ricardf-cmp]

Well, I found out a workaround. I renamed the thread name for something that contained "TestNG" and that allowed me to keep the tests under the same thread:

Thread.currentThread().setName("TestNG-" + testname);

@cbeust , until the fix for this bug is not comming, do you have any idea what kind of implications would this mean if I use this hack together with a timeout on @Test methods?

The problem here is that I use too many features probably heh, retryanalizer, dataproviders, timeouts, etc all at the same time heh.

[ricardf-cmp]

@juherr Sorry I was writing my last comment when you sent your answer. I double checked, that "invokeHookable(...)" is only used inside an if condition like:

https://github.com/cbeust/testng/blob/testng-6.9.5/src/main/java/org/testng/internal/Invoker.java#L633

        // If no timeOut, just invoke the method
        if (MethodHelper.calculateTimeOut(tm) <= 0) {
          [...]
            MethodInvocationHelper.invokeHookable(instance,
                parameterValues, hookableInstance, thisMethod, testResult);
          [...]
        }
        else {
          [...]
          MethodInvocationHelper.invokeWithTimeout(tm, instance, parameterValues, testResult);
        }
      }

And that "invokeWithTimeout" does NOT call the run method in iHookable :(

[juherr]

The call is not direct, but: "invokeWithTimeout" -> "invokeWithTimeoutWith*Executor" -> "InvokeMethodRunnable#run()#runOne()" -> "invokeHookable" -> "hookable.run(....)"

[ricardf-cmp]

I just tested out... I was using TestNG 6.9.4 but when upgraded to 6.9.5 and now it uses the IHookable run! I just compared both versions and you guys just added/fixed that. Thanks for pointing me to the right direction!

I use a log4j setup that logs into files, one per thread. Your thread magic when there's a timeout was breaking that logging set up heh.

[juherr]

I use a log4j setup that logs into files, one per thread. Your thread magic when there's a timeout was breaking that logging set up heh.

I don't see any solution to fix this issue for the moment.

[DzmitryHumianiuk]

reference.
blocker for reportportal/client-java-core#6