NullPointerException when using mvn argLine option

[Ahmadreza-SY]

Hi,

I am running JUnit test cases in Maven with SELogger on open-source projects. I can successfully run the test cases in most cases. But sometimes I get NullPointerException when using SELogger and the test case passes when I am not using SELogger.

I am using selogger-0.5.0.jar, Maven 3.8.6, and OpenJDK 1.8.0_302.

Here is an example in the apache/shardingsphere project when checking out commit 43254af:

The Maven command:

mvn test -pl shardingsphere-features/shardingsphere-sharding/shardingsphere-sharding-route/pom.xml --also-make -Dsurefire.failIfNoSpecifiedTests=false -Dtest="ShardingUpdateStatementValidatorTest#assertValidateUpdateWithoutShardingKey" -Dcheckstyle.skip=true -Dspotless.apply.skip=true --batch-mode -DargLine="-javaagent:/path/to/selogger.jar=format=nearomni,exlocation=.m2,output=/path/to/trace"

The Maven log:

[INFO] -------------------------------------------------------
[INFO]  T E S T S
[INFO] -------------------------------------------------------
[INFO] Running org.apache.shardingsphere.sharding.route.engine.validator.impl.ShardingUpdateStatementValidatorTest
[ERROR] Tests run: 1, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 0.862 s <<< FAILURE! - in org.apache.shardingsphere.sharding.route.engine.validator.impl.ShardingUpdateStatementValidatorTest
[ERROR] assertValidateUpdateWithoutShardingKey(org.apache.shardingsphere.sharding.route.engine.validator.impl.ShardingUpdateStatementValidatorTest)  Time elapsed: 0.005 s  <<< ERROR!
java.lang.NullPointerException
        at org.apache.shardingsphere.sharding.route.engine.validator.impl.ShardingUpdateStatementValidatorTest.assertValidateUpdateWithoutShardingKey(ShardingUpdateStatementValidatorTest.java:71)

[INFO] 
[INFO] Results:
[INFO] 
[ERROR] Errors: 
[ERROR]   ShardingUpdateStatementValidatorTest.assertValidateUpdateWithoutShardingKey:71 » NullPointer
[INFO] 
[ERROR] Tests run: 1, Failures: 0, Errors: 1, Skipped: 0
[INFO]

But when I run this command:

mvn test -pl shardingsphere-features/shardingsphere-sharding/shardingsphere-sharding-route/pom.xml --also-make -Dsurefire.failIfNoSpecifiedTests=false -Dtest="ShardingUpdateStatementValidatorTest#assertValidateUpdateWithoutShardingKey" -Dcheckstyle.skip=true -Dspotless.apply.skip=true --batch-mode

The test case passes:

[INFO] -------------------------------------------------------
[INFO]  T E S T S
[INFO] -------------------------------------------------------
[INFO] Running org.apache.shardingsphere.sharding.route.engine.validator.impl.ShardingUpdateStatementValidatorTest
[INFO] Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.076 s - in org.apache.shardingsphere.sharding.route.engine.validator.impl.ShardingUpdateStatementValidatorTest
[INFO] 
[INFO] Results:
[INFO] 
[INFO] Tests run: 1, Failures: 0, Errors: 0, Skipped: 0
[INFO]

[takashi-ishio]

Thank you for your detailed report. I confirmed the same behavior on my environment.

[takashi-ishio]

The problem is likely caused by a conflict between SELogger and Mockito. The test case uses a mock object as follows:

when(shardingRule.isShardingColumn("id", "user")).thenReturn(false);

SELogger directly calls the isShardingColumn method as is. As mockito creates an shardingRule object but without a regular initialization, the call uses a field that has not been initialized, and then causes a NPE.

[takashi-ishio]

This might be a corner case for Mockito. When I changed the Mockito version of the pom.xml file to 2.28.2, then the build succeeded (isShardingColumn method was never called). It may take time to further investigate this problem.

[Ahmadreza-SY]

Thank for the explanation. I cannot change the versions of the libraries because I am collecting data from these projects.

I found another case with a different error in af515583

Original command:

mvn test -pl pom.xml --also-make -Dsurefire.failIfNoSpecifiedTests=false -Dtest="TryCatchTest#testTryWithVariableAsResource" --batch-mode

SELogger command:

mvn test -pl pom.xml --also-make -Dsurefire.failIfNoSpecifiedTests=false -Dtest="TryCatchTest#testTryWithVariableAsResource" --batch-mode -DargLine="-javaagent:selogger.jar=format=nearomni,exlocation=.m2,e=com/gradle,output=report"

Error when running with SELogger:

[INFO] Running spoon.test.trycatch.TryCatchTest
[ERROR] Tests run: 1, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 1.359 s <<< FAILURE! - in spoon.test.trycatch.TryCatchTest
[ERROR] spoon.test.trycatch.TryCatchTest.testTryWithVariableAsResource  Time elapsed: 1.337 s  <<< ERROR!
java.util.ServiceConfigurationError: java.nio.file.spi.FileSystemProvider: Provider jdk.nio.zipfs.ZipFileSystemProvider could not be instantiated
    at java.base/java.util.ServiceLoader.fail(ServiceLoader.java:582)
    at java.base/java.util.ServiceLoader$ProviderImpl.newInstance(ServiceLoader.java:804)
    at java.base/java.util.ServiceLoader$ProviderImpl.get(ServiceLoader.java:722)
    at java.base/java.util.ServiceLoader$3.next(ServiceLoader.java:1395)
    at java.base/java.nio.file.spi.FileSystemProvider.loadInstalledProviders(FileSystemProvider.java:155)
    at java.base/java.nio.file.spi.FileSystemProvider$1.run(FileSystemProvider.java:205)
    at java.base/java.nio.file.spi.FileSystemProvider$1.run(FileSystemProvider.java:202)
    at java.base/java.security.AccessController.doPrivileged(Native Method)
    at java.base/java.nio.file.spi.FileSystemProvider.installedProviders(FileSystemProvider.java:202)
    ...
Caused by: java.lang.NoClassDefFoundError: selogger/logging/Logging
    at jdk.zipfs/jdk.nio.zipfs.ZipFileSystemProvider.<init>(ZipFileSystemProvider.java)
    at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
    at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
    at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:490)
    at java.base/java.util.ServiceLoader$ProviderImpl.newInstance(ServiceLoader.java:780)
    ... 103 more
Caused by: java.lang.ClassNotFoundException: selogger.logging.Logging
    at java.base/jdk.internal.loader.BuiltinClassLoader.loadClass(BuiltinClassLoader.java:581)
    at java.base/java.lang.ClassLoader.loadClass(ClassLoader.java:522)
    ... 109 more

[takashi-ishio]

Thank you for the additional information. I will check it later.

For the case of apache/shardingsphere, SELogger somehow breaks a mock target class ShardingRule. Mockito could not create a Mock object and uses a regular instance instead.
An additional option e=org/apache/shardingsphere/sharding/rule/ShardingRule keeps the mocked class as is and avoids the error. As the class is actually never used in the test case, I hope it can be a workaround for you.

[takashi-ishio]

For the new case, you can avoid the problem by adding e=jdk. The package should be excluded from logging by default but it was not included in the default filter of SELogger. I will update the default configuration for that in the next version.

[Ahmadreza-SY]

Thank you very much for the suggestions. I will try them out.

[takashi-ishio]

I found that weave=LABEL causes a crash. Other weave configurations without LABEL do not cause a crash. Changing weave option is another workaround.

[takashi-ishio]

I found that weave=LABEL added instructions after the final label located at the end of a method. It resulted in unreachable instructions. They conflicted with Mockito.

I fixed the problem in 2b4548. The new version works with the reported case on my environment.