Skip to content

Instantly share code, notes, and snippets.

@dkorobtsov
Last active February 1, 2018 21:10
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save dkorobtsov/0d121bcb11a3c421e0dbc7ea93f0c8bc to your computer and use it in GitHub Desktop.
Save dkorobtsov/0d121bcb11a3c421e0dbc7ea93f0c8bc to your computer and use it in GitHub Desktop.
SelenideLogger - Reproducing NPE
package tests.unit.selenideresearch;
import com.codeborne.selenide.testng.GlobalTextReport;
import org.testng.annotations.Listeners;
import org.testng.annotations.Test;
@Listeners({GlobalTextReport.class, TestListener.class})
public class SelenideLoggerIssueTest1 {
@Test
@TestAnnotation
public void testDummy1() {
System.out.println("Test1");
}
@Test
public void testDummy2() {
System.out.println("Test2");
}
}
package tests.unit.selenide;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.testng.annotations.Listeners;
import org.testng.annotations.Test;
@Listeners({TestListener.class})
public class SelenideLoggerIssueTest3 {
private static final Logger log = LogManager.getLogger(SelenideLoggerIssueTest4.class);
@Test
@TestAnnotation
public void testDummy1() {
log.debug("Test1");
}
@Test
public void testDummy2() {
log.debug("Test2");
}
}
package tests.unit.selenide;
import com.codeborne.selenide.testng.GlobalTextReport;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.testng.annotations.Listeners;
import org.testng.annotations.Test;
@Listeners({GlobalTextReport.class, TestListener.class})
public class SelenideLoggerIssueTest4 {
private static final Logger log = LogManager.getLogger(SelenideLoggerIssueTest4.class);
@Test
@TestAnnotation
public void testDummy1() {
log.debug("Test1");
}
@Test
public void testDummy2() {
log.debug("Test2");
}
}
package tests.unit.selenide;
import java.lang.annotation.ElementType;
import java.lang.annotation.Retention;
import java.lang.annotation.RetentionPolicy;
import java.lang.annotation.Target;
@Target({ElementType.TYPE, ElementType.METHOD})
@Retention(RetentionPolicy.RUNTIME)
public @interface TestAnnotation {
}
package tests.unit.selenide;
import org.testng.*;
import org.testng.internal.ConstructorOrMethod;
public class TestListener implements IInvokedMethodListener2 {
@Override
public void beforeInvocation(IInvokedMethod method, ITestResult testResult, ITestContext context) {
ConstructorOrMethod consOrMethod = method.getTestMethod().getConstructorOrMethod();
TestAnnotation testAnnotation = consOrMethod.getMethod().getAnnotation(TestAnnotation.class);
if (testAnnotation != null) {
throw new SkipException("Skipping test");
}
}
@Override
public void afterInvocation(IInvokedMethod method, ITestResult testResult, ITestContext context) {
}
@Override
public void beforeInvocation(IInvokedMethod method, ITestResult testResult) {
}
@Override
public void afterInvocation(IInvokedMethod method, ITestResult testResult) {
}
}
@dkorobtsov
Copy link
Author

dkorobtsov commented Jan 30, 2018

Steps to reproduce:

  1. Add log4j2, TestNG and Selenide dependencies.
  2. Copy all files to some package
  3. Run SelenideLoggerIssueTest3 to get expected result
  4. Run SelenideLoggerIssueTest4 to get actual result (NPE and other interesting problems)

Expected result (this is how Test3 without SelenideLogger works):
screen shot 2018-01-30 at 11 20 42

Actual result (this is how Test4 with SelenideLogger works):
screen shot 2018-01-30 at 11 18 21

After some experiments it feels like in certain cases SelenideLogger is conflicting with log4j2 logger.
As a result we get NPE and 3 instances of the same test:
instance 1 is failed test
instance 2 is skipped test
instance 3 is never completed

P.S. Update: feels like log4j2 logger is not the case, absolutely same result with simple console output(SelenideLoggerIssueTest1).
(Initially left that of of scope of this gist cause for some mysterious reasons issue was not reproducing with this example.

Looks like root cause is the one I was initially suspecting:
If test is canceled or removed from suite scope for any reason on beforeInvocation event, SelenideLogger start() is not called.
At the same time afterInvocation event is called anyway, as a result SelenideLogger is attempting to call finish() with null context.

Locally for my own purposes I solved issue by adding boolean selenideLoggingStarted field. If it's false, finish() won't be called.
In general it completely solved all problems I had. If that solution is acceptable, I can send another pull request.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment