Failing unit tests in a clean clone of the repository

[seanrobbins]

1. What did you do?

• Took a clean clone of java-tron master on macOS High Sierra
• ran 'gradle test'

2. What did you expect to see?
   All unit tests passing

3. What did you see instead?
   2 failing tests and 3 skipped (but build reported as successful in spite of the failing tests)

Failed tests:

org.tron.core.BlockchainTest > testAddBlockToChain FAILED
java.lang.RuntimeException at BlockchainTest.java:142
Caused by: org.fusesource.leveldbjni.internal.NativeDB$DBException at BlockchainTest.java:142

org.tron.core.BlockchainTest > testFindTransaction FAILED
java.lang.RuntimeException at BlockchainTest.java:87
Caused by: org.fusesource.leveldbjni.internal.NativeDB$DBException at BlockchainTest.java:87

Skipped tests:

org.tron.datasource.leveldb.LevelDbDataSourceTest > testGet SKIPPED

org.tron.datasource.leveldb.LevelDbDataSourceTest > testPut SKIPPED

org.tron.datasource.leveldb.LevelDbDataSourceTest > testRest SKIPPED

[wailo]

I have the same setup, but can't reproduce.

Java
java 9.0.1
Java(TM) SE Runtime Environment (build 9.0.1+11)
Java HotSpot(TM) 64-Bit Server VM (build 9.0.1+11, mixed mode)

Gradle
Gradle 4.4.1
Build time: 2017-12-20 15:45:23 UTC
Revision: 10ed9dc355dc39f6307cc98fbd8cea314bdd381c

Groovy: 2.4.12
Ant: Apache Ant(TM) version 1.9.9 compiled on February 2 2017
JVM: 9.0.1 (Oracle Corporation 9.0.1+11)
OS: Mac OS X 10.13.2 x86_64

[seanrobbins]

My setup looks identical. I have pulled the latest and I can still recreate.

Java
Java 9.0.1
Java(TM) SE Runtime Environment (build 9.0.1+11)
Java HotSpot(TM) 64-Bit Server VM (build 9.0.1+11, mixed mode)

Gradle 4.4.1

Build time: 2017-12-20 15:45:23 UTC
Revision: 10ed9dc355dc39f6307cc98fbd8cea314bdd381c

Groovy: 2.4.12
Ant: Apache Ant(TM) version 1.9.9 compiled on February 2 2017
JVM: 9.0.1 (Oracle Corporation 9.0.1+11)
OS: Mac OS X 10.13.2 x86_64

[seanrobbins]

I see this error when I run a clean build, possibly related? :

../java-tron/src/test/java/org/tron/datasource/leveldb/LevelDbDataSourceTest.java:25: warning: lombok.javac.apt.LombokProcessor could not be initialized. Lombok will not run during this compilation: java.lang.IllegalArgumentException: com.sun.tools.javac.api.ClientCodeWrapper$WrappedStandardJavaFileManager extends com.sun.tools.javac.api.ClientCodeWrapper$WrappedJavaFileManager implements javax.tools.StandardJavaFileManager

[wailo]

Yes, I get the same warnings with Java 9, 3 tests are skipped, the rest are passing.
For sake of experiment, I am downgraded to java 8, and now I don't see the warnings anymore. I paste below a copy of the build and test log.

`$ git clean -dxf && gradle build && gradle test
Removing .gradle/
Removing build/
Removing database/
Removing logs/

Task :generateProto
Using TaskInputs.file() with something that doesn't resolve to a File object has been deprecated and is scheduled to be removed in Gradle 5.0. Use TaskInputs.files() instead.

Task :compileJava
Note: /Users/wa/sandbox/forked_tron/src/main/java/org/tron/crypto/ECKey.java uses or overrides a deprecated API.
Note: Recompile with -Xlint:deprecation for details.
Note: Some input files use unchecked or unsafe operations.
Note: Recompile with -Xlint:unchecked for details.

Task :test

org.tron.datasource.leveldb.LevelDbDataSourceTest > testGet SKIPPED

org.tron.datasource.leveldb.LevelDbDataSourceTest > testPut SKIPPED

org.tron.datasource.leveldb.LevelDbDataSourceTest > testRest SKIPPED

org.tron.core.TransactionUtilsTest > testNewCoinbaseTransaction PASSED

org.tron.core.TransactionUtilsTest > testGetHash PASSED

org.tron.core.TransactionUtilsTest > testParseTransaction PASSED

org.tron.core.TransactionUtilsTest > testToPrintString PASSED

org.tron.core.TransactionUtilsTest > testIsCoinbaseTransaction PASSED

org.tron.core.BlockUtilsTest > testPrepareData PASSED

org.tron.core.BlockUtilsTest > testNewGenesisBlock PASSED

org.tron.core.BlockUtilsTest > testGetPowBoundary PASSED

org.tron.core.BlockUtilsTest > testToPrintString PASSED

org.tron.core.BlockUtilsTest > testIsValidate PASSED

org.tron.core.BlockUtilsTest > testGetMineValue PASSED

BUILD SUCCESSFUL in 11s
14 actionable tasks: 14 executed

Task :generateProto UP-TO-DATE
Using TaskInputs.file() with something that doesn't resolve to a File object has been deprecated and is scheduled to be removed in Gradle 5.0. Use TaskInputs.files() instead.

BUILD SUCCESSFUL in 0s
10 actionable tasks: 10 up-to-date
`

[seanrobbins]

I can confirm the lombok warnings with Java 9 are unrelated. Can get rid of them by changing the lombok version to the edge release available here: https://projectlombok.org/download-edge

So, it looks like that warning will be fixed when lombok 1.16.19 is available.

[seanrobbins]

Going to try digging a bit more into the error:

org.tron.core.BlockchainTest > testFindTransaction FAILED
java.lang.RuntimeException at BlockchainTest.java:87
Caused by: org.fusesource.leveldbjni.internal.NativeDB$DBException at BlockchainTest.java:87

Line 87 of BlockchainTest.java is simply: Blockchain blockchain = new Blockchain();

[seanrobbins]

Seems to be some issue with the library:

compile group: 'org.fusesource.leveldbjni', name: 'leveldbjni-all',
        version: '1.8'

As it is not affecting others running the code, it may be specific to my machine's configuration. I can try on another development machine.

I do not believe this is an issue with java-tron codebase itself.

[seanrobbins]

Looks like I have resolved this by running: git clean -dxf

Not sure what the underlying issue was. Although interestingly, I don't see BlockchainTest results in the test output at all.

Closing this issue.

[Eyesonly88]

@seanrobbins hmm I get null pointer exception (using the latest code as of today). I think there is something wrong with the findTransaction function inside Blockchain.java. This testFindTransaction test is the only test for this function. It looks complicated and should have way more tests.

[wailo]

Did a clean build and test with: git reset HEAD --hard && git clean -dxf && git pull && gradle build && gradle test
Can't reproduce.

[seanrobbins]

@Eyesonly88 I get that same NullPointerException when I run BlockchainTest.testFindTransaction in IntelliJ.

Also, if I run the full BlockchainTest suite, some of the tests do not run.

I'm trying to figure out what is happening there and may open a new issue.

[seanrobbins]

@wailo Can you check your results and see if you can find passing tests from the BlockchainTest suite?

I can't see BlockchainTest in the test results you posted in a previous comment above.

[seanrobbins]

I'm re-opening this. After more investigation I am now convinced there is a real issue, which is not always seen due to another issue for which I am going to open another ticket.

When these test DO run from Gradle (I have to do some code manipulation to ensure that they run) and I have the -debug option on, the full error message can be seen:

14:17:22.450 [DEBUG] [TestEventLogger] org.tron.core.BlockchainTest > testFindTransaction FAILED
14:17:22.451 [DEBUG] [TestEventLogger] java.lang.RuntimeException: Can't initialize database
14:17:22.451 [DEBUG] [TestEventLogger] at org.tron.datasource.leveldb.LevelDbDataSource.init(LevelDbDataSource.java:96)
14:17:22.451 [DEBUG] [TestEventLogger] at org.tron.core.Blockchain.(Blockchain.java:97)
14:17:22.451 [DEBUG] [TestEventLogger] at org.tron.core.BlockchainTest.testFindTransaction(BlockchainTest.java:88)
14:17:22.451 [DEBUG] [TestEventLogger] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
14:17:22.451 [DEBUG] [TestEventLogger] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
14:17:22.452 [DEBUG] [TestEventLogger] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
14:17:22.452 [DEBUG] [TestEventLogger] at java.lang.reflect.Method.invoke(Method.java:498)
14:17:22.452 [DEBUG] [TestEventLogger] at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
14:17:22.452 [DEBUG] [TestEventLogger] at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
14:17:22.452 [DEBUG] [TestEventLogger] at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
14:17:22.452 [DEBUG] [TestEventLogger] at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
14:17:22.452 [DEBUG] [TestEventLogger] at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
14:17:22.453 [DEBUG] [TestEventLogger] at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
14:17:22.453 [DEBUG] [TestEventLogger] at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
14:17:22.453 [DEBUG] [TestEventLogger] at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
14:17:22.453 [DEBUG] [TestEventLogger] at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
14:17:22.453 [DEBUG] [TestEventLogger] at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
14:17:22.453 [DEBUG] [TestEventLogger] at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
14:17:22.453 [DEBUG] [TestEventLogger] at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
14:17:22.454 [DEBUG] [TestEventLogger] at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
14:17:22.454 [DEBUG] [TestEventLogger] at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:114)
14:17:22.454 [DEBUG] [TestEventLogger] at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:57)
14:17:22.454 [DEBUG] [TestEventLogger] at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:66)
14:17:22.454 [DEBUG] [TestEventLogger] at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:51)
14:17:22.454 [DEBUG] [TestEventLogger] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
14:17:22.455 [DEBUG] [TestEventLogger] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
14:17:22.455 [DEBUG] [TestEventLogger] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
14:17:22.455 [DEBUG] [TestEventLogger] at java.lang.reflect.Method.invoke(Method.java:498)
14:17:22.455 [DEBUG] [TestEventLogger] at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
14:17:22.455 [DEBUG] [TestEventLogger] at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
14:17:22.455 [DEBUG] [TestEventLogger] at org.gradle.internal.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
14:17:22.455 [DEBUG] [TestEventLogger] at org.gradle.internal.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
14:17:22.456 [DEBUG] [TestEventLogger] at com.sun.proxy.$Proxy3.processTestClass(Unknown Source)
14:17:22.456 [DEBUG] [TestEventLogger] at org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:109)
14:17:22.456 [DEBUG] [TestEventLogger] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
14:17:22.456 [DEBUG] [TestEventLogger] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
14:17:22.456 [DEBUG] [TestEventLogger] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
14:17:22.456 [DEBUG] [TestEventLogger] at java.lang.reflect.Method.invoke(Method.java:498)
14:17:22.456 [DEBUG] [TestEventLogger] at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
14:17:22.456 [DEBUG] [TestEventLogger] at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
14:17:22.457 [DEBUG] [TestEventLogger] at org.gradle.internal.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:377)
14:17:22.457 [DEBUG] [TestEventLogger] at org.gradle.internal.concurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:54)
14:17:22.457 [DEBUG] [TestEventLogger] at org.gradle.internal.concurrent.StoppableExecutorImpl$1.run(StoppableExecutorImpl.java:40)
14:17:22.457 [DEBUG] [TestEventLogger] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
14:17:22.457 [DEBUG] [TestEventLogger] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
14:17:22.457 [DEBUG] [TestEventLogger] at java.lang.Thread.run(Thread.java:748)
14:17:22.457 [DEBUG] [TestEventLogger]
14:17:22.458 [DEBUG] [TestEventLogger] Caused by:
14:17:22.458 [DEBUG] [TestEventLogger] org.fusesource.leveldbjni.internal.NativeDB$DBException: IO error: lock /Users/sean/java-tron/database-test/block_data/LOCK: already held by process
14:17:22.458 [DEBUG] [TestEventLogger] at org.fusesource.leveldbjni.internal.NativeDB.checkStatus(NativeDB.java:200)
14:17:22.459 [DEBUG] [TestEventLogger] at org.fusesource.leveldbjni.internal.NativeDB.open(NativeDB.java:218)
14:17:22.459 [DEBUG] [TestEventLogger] at org.fusesource.leveldbjni.JniDBFactory.open(JniDBFactory.java:168)
14:17:22.459 [DEBUG] [TestEventLogger] at org.tron.datasource.leveldb.LevelDbDataSource.init(LevelDbDataSource.java:85)
14:17:22.459 [DEBUG] [TestEventLogger] ... 45 more

It looks like the test tries to access LevelDB which is locked by another process (possibly a previous test).