I am trying to setup a jmh test for orient db embedded. The test suite is as follows:
@State(Scope.Benchmark)
public class OrientDbTest {
private OObjectDatabaseTx db;
private Person[] personList;
@Setup
public void setUp() throws IOException {
deleteDir("/tmp/orientdb/");
db = new OObjectDatabaseTx("plocal:/tmp/orientdb/person").create();
ODatabaseRecordThreadLocal.INSTANCE.set(db.getUnderlying());
loadData();
}
@TearDown
public void cleanUp() {
if (db != null) {
ODatabaseRecordThreadLocal.INSTANCE.set(db.getUnderlying());
db.commit();
db.drop();
db.close();
}
}
@Benchmark
@BenchmarkMode(Mode.AverageTime)
@OutputTimeUnit(TimeUnit.MICROSECONDS)
public void benchmarkInsertCompany() {
ODatabaseRecordThreadLocal.INSTANCE.set(db.getUnderlying());
db.getEntityManager().registerEntityClass(Person.class);
for (Person person : personList) {
db.save(person);
}
}
void loadData() throws IOException {
InputStream inputStream = Thread.currentThread().getContextClassLoader().getResourceAsStream("data.json");
ObjectMapper objectMapper = new ObjectMapper();
personList = objectMapper.readValue(inputStream, Person[].class);
}
void deleteDir(String dirName) {
File file = new File(dirName);
if (file.exists()) {
File[] files = file.listFiles();
if (files != null) {
for (File child : files) {
if (child.isDirectory()) {
deleteDir(child.getAbsolutePath());
} else {
child.delete();
}
}
} else {
file.delete();
}
}
}
}
This project is a gradle project and I am running using gradle-jmh plugin. Here is the jmh settings in build.gradle file:
jmh {
jmhVersion = '1.14'
iterations = 10 // Number of measurement iterations to do.
fork = 2 // How many times to forks a single benchmark. Use 0 to disable forking altogether
jvmArgs = '-server -XX:MaxDirectMemorySize=15986m'
resultsFile = project.file("${project.buildDir}/reports/jmh/results.txt") // results file
profilers = ['cl', 'gc', 'hs_thr'] // Use profilers to collect additional data. Supported profilers: [cl, comp, gc, stack, perf, perfnorm, perfasm, xperf, xperfasm, hs_cl, hs_comp, hs_gc, hs_rt, hs_thr]
resultFormat = 'CSV' // Result format type (one of CSV, JSON, NONE, SCSV, TEXT)
threads = 4 // Number of worker threads to run with.
timeUnit = 'ms' // Output time unit. Available time units are: [m, s, ms, us, ns].
warmupForks = 2 // How many warmup forks to make for a single benchmark. 0 to disable warmup forks.
warmupIterations = 10 // Number of warmup iterations to do.
}
When I am running the test, I am getting below error:
INFO: OrientDB auto-config DISKCACHE=10,384MB (heap=3,554MB direct=15,986MB os=15,986MB)
<failure>
com.orientechnologies.orient.core.exception.OStorageExistsException: Cannot create new storage 'plocal:/tmp/orientdb/person' because it is not closed
DB name="person"
at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.create(OAbstractPaginatedStorage.java:423)
at com.orientechnologies.orient.core.storage.impl.local.paginated.OLocalPaginatedStorage.create(OLocalPaginatedStorage.java:125)
at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.create(ODatabaseDocumentTx.java:429)
at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.create(ODatabaseDocumentTx.java:389)
at com.orientechnologies.orient.core.db.ODatabaseWrapperAbstract.create(ODatabaseWrapperAbstract.java:75)
at org.dizitart.no2.benchmark.OrientDbTest.setUp(OrientDbTest.java:24)
at org.dizitart.no2.benchmark.generated.OrientDbTest_benchmarkInsertCompany_jmhTest._jmh_tryInit_f_orientdbtest0_G(OrientDbTest_benchmarkInsertCompany_jmhTest.java:400)
at org.dizitart.no2.benchmark.generated.OrientDbTest_benchmarkInsertCompany_jmhTest.benchmarkInsertCompany_AverageTime(OrientDbTest_benchmarkInsertCompany_jmhTest.java:149)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:430)
at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:412)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
What am I doing wrong in the setup here?
EDIT:
After reading this, I modified the code as follows:
public class OrientDbTest {
@State(Scope.Benchmark)
public static class TestState {
private OObjectDatabaseTx db;
private Person[] personList;
private BenchmarkTestHelper testHelper = new BenchmarkTestHelper();
@Setup(Level.Trial)
public void setUp() throws IOException {
System.out.println("started setup code");
testHelper.deleteDir("/tmp/orientdb/");
try {
db = new OObjectDatabaseTx("plocal:/tmp/orientdb/person").open(null, null);
db.getEntityManager().registerEntityClass(Person.class);
personList = testHelper.loadData();
} finally {
if (db != null) {
db.close();
}
}
}
@TearDown(Level.Trial)
public void cleanUp() {
System.out.println("started cleanup code");
if (db != null) {
ODatabaseRecordThreadLocal.INSTANCE.set(db.getUnderlying());
db.commit();
db.drop();
db.close();
}
}
}
@Benchmark
@BenchmarkMode(Mode.AverageTime)
@OutputTimeUnit(TimeUnit.MICROSECONDS)
public void benchmarkInsertCompany(TestState state, Blackhole blackhole) {
OObjectDatabaseTx db = state.db;
Person[] personList = state.personList;
ODatabaseRecordThreadLocal.INSTANCE.set(db.getUnderlying());
for (Person person : personList) {
blackhole.consume(db.save(person));
}
}
}
class BenchmarkTestHelper {
Person[] loadData() throws IOException {
InputStream inputStream = Thread.currentThread().getContextClassLoader().getResourceAsStream("data.json");
ObjectMapper objectMapper = new ObjectMapper();
return objectMapper.readValue(inputStream, Person[].class);
}
void deleteDir(String dirName) {
File file = new File(dirName);
if (file.exists()) {
File[] files = file.listFiles();
if (files != null) {
for (File child : files) {
if (child.isDirectory()) {
deleteDir(child.getAbsolutePath());
} else {
child.delete();
}
}
file.delete();
} else {
file.delete();
}
}
}
}
After the new setup, I am getting below error:
# JMH 1.14 (released 19 days ago)
# VM version: JDK 1.8.0_77, VM 25.77-b03
# VM invoker: /home/anindya/app/jdk1.8.0_77/jre/bin/java
# VM options: -server -XX:MaxDirectMemorySize=15986m
# Warmup: 10 iterations, 1 s each
# Measurement: 10 iterations, 1 s each
# Timeout: 10 min per iteration
# Threads: 4 threads, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: org.dizitart.no2.benchmark.OrientDbTest.benchmarkInsertCompany
# Run progress: 50.00% complete, ETA 00:01:28
# Warmup Fork: 1 of 2
# Warmup Iteration 1: started setup code
Sep 26, 2016 11:15:57 AM com.orientechnologies.common.log.OLogManager log
INFO: OrientDB auto-config DISKCACHE=10,384MB (heap=3,554MB direct=15,986MB os=15,986MB)
started setup code
started setup code
started setup code
<failure>
com.orientechnologies.orient.core.exception.OStorageExistsException: Cannot create new storage 'plocal:/tmp/orientdb/person' because it is not closed
DB name="person"
at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.create(OAbstractPaginatedStorage.java:423)
at com.orientechnologies.orient.core.storage.impl.local.paginated.OLocalPaginatedStorage.create(OLocalPaginatedStorage.java:125)
at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.create(ODatabaseDocumentTx.java:429)
at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.create(ODatabaseDocumentTx.java:389)
at com.orientechnologies.orient.core.db.ODatabaseWrapperAbstract.create(ODatabaseWrapperAbstract.java:75)
at org.dizitart.no2.benchmark.OrientDbTest$TestState.setUp(OrientDbTest.java:28)
at org.dizitart.no2.benchmark.generated.OrientDbTest_benchmarkInsertCompany_jmhTest._jmh_tryInit_f_teststate1_G(OrientDbTest_benchmarkInsertCompany_jmhTest.java:409)
at org.dizitart.no2.benchmark.generated.OrientDbTest_benchmarkInsertCompany_jmhTest.benchmarkInsertCompany_AverageTime(OrientDbTest_benchmarkInsertCompany_jmhTest.java:153)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:430)
at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:412)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
...
# Run progress: 87.50% complete, ETA 00:00:18
# Fork: 2 of 2
# Warmup Iteration 1: started setup code
Sep 26, 2016 11:16:38 AM com.orientechnologies.common.log.OLogManager log
INFO: OrientDB auto-config DISKCACHE=10,384MB (heap=3,554MB direct=15,986MB os=15,986MB)
started setup code
started setup code
started setup code
<failure>
java.lang.ClassCastException: com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx cannot be cast to com.orientechnologies.orient.object.db.OObjectDatabaseTx
at org.dizitart.no2.benchmark.OrientDbTest$TestState.setUp(OrientDbTest.java:28)
at org.dizitart.no2.benchmark.generated.OrientDbTest_benchmarkInsertCompany_jmhTest._jmh_tryInit_f_teststate1_G(OrientDbTest_benchmarkInsertCompany_jmhTest.java:409)
at org.dizitart.no2.benchmark.generated.OrientDbTest_benchmarkInsertCompany_jmhTest.benchmarkInsertCompany_AverageTime(OrientDbTest_benchmarkInsertCompany_jmhTest.java:153)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:430)
at org.openjdk.jmh.runner.BenchmarkHandler$BenchmarkTask.call(BenchmarkHandler.java:412)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
Sep 26, 2016 11:16:49 AM com.orientechnologies.common.log.OLogManager log
INFO: Orient Engine is shutting down...
Sep 26, 2016 11:16:49 AM com.orientechnologies.common.log.OLogManager log
INFO: - shutdown storage: person...
Okay, so there are couple of troubles:
a) The setUp() method itself is buggy, it throws:
java.lang.ClassCastException: com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx cannot be cast to com.orientechnologies.orient.object.db.OObjectDatabaseTx
at jmh.demo.OrientDbTest$TestState.setUp(OrientDbTest.java:30)
at jmh.demo.generated.OrientDbTest_benchmarkInsert_jmhTest._jmh_tryInit_f_teststate1_G(OrientDbTest_benchmarkInsert_jmhTest.java:409)
at jmh.demo.generated.OrientDbTest_benchmarkInsert_jmhTest.benchmarkInsert_AverageTime(OrientDbTest_benchmarkInsert_jmhTest.java:153)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
...
b) @Setup method for @State(Benchmark) is supposed to be executed only once. But, due to the bug in JMH, if first thread failed with the exception above, then other threads would also try to enter @Setup and then they will try to open the database, but fail, because it is already open?
In fact, the failure (a) is visible even in the original post, and what exception would get reported from multiple threads entering @Setup would depend on sheer luck (this got better in JMH 1.14.1). It reliably fails with that proper exception if you set threads=1. Also, the cleanup path in setUp() does not look consistent with tearDown(), which may explain why re-entered threads fail to open the DB.
Bottom-line: before doing multi-threaded tests, try doing the single-threaded.