Jmh task run from buildship fails to acquire jmh lock, works fine from shell


(davidmichaelkarr) #1

I’m trying to use https://github.com/melix/jmh-gradle-plugin to build a JMH benchmark. What I have works fine from the shell (even though the methods to benchmark are still empty), but when I run the “jmh” task from buildship, I get this:

Caused by: org.openjdk.jmh.runner.RunnerException: ERROR: Exception while trying to acquire the JMH lock (C:\Windows/jmh.lock): Access is denied, exiting. Use -Djmh.ignoreLock=true to forcefully continue.
at org.openjdk.jmh.runner.Runner.run(Runner.java:213)
at me.champeau.gradle.IsolatedRunner.run(IsolatedRunner.java:38)
… 12 more

So searching the net for this message (and just reading the error message) I tried to set the jvm args as follows:

jmh {
    jvmArgs = ['-Djmh.ignoreLock=true']
    jmhVersion = '1.19'
}

I first tested this from the command line and verified that the “jvmArgs” setting was acknowledged. It still works fine from the shell, but still fails with the same error from buildship.

Here is the console output from running the task in Buildship:

	Working Directory: C:\Users\me\workspace\jsonpathexperiments
Gradle User Home: C:\Users\me\.gradle
Gradle Distribution: Specific Gradle version 4.1
Gradle Version: 4.1
Java Home: C:\Program Files\Java\jdk1.8.0_102
JVM Arguments: None
Program Arguments: --info --stacktrace
Build Scans Enabled: false
Offline Mode Enabled: false
Gradle Tasks: jmh

The client will now receive all logging from the daemon (pid: 10740). The daemon log file: C:\Users\me\.gradle\daemon\4.1\daemon-10740.out.log
Starting 28th build in daemon [uptime: 1 hrs 17 mins 8.436 secs, performance: 99%, no major garbage collections]
Using 8 worker leases.
Creating new cache for fileHashes, path C:\Users\me\workspace\jsonpathexperiments\.gradle\4.1\fileHashes\fileHashes.bin, access org.gradle.cache.internal.DefaultCacheAccess@4deb2494
Creating new cache for plugin-use-metadata, path C:\Users\me\.gradle\caches\4.1\plugin-resolution\plugin-use-metadata.bin, access org.gradle.cache.internal.DefaultCacheAccess@a86a24f
Creating new cache for client-status, path C:\Users\me\.gradle\caches\4.1\plugin-resolution\client-status.bin, access org.gradle.cache.internal.DefaultCacheAccess@a86a24f
Starting Build
Settings evaluated using settings file 'C:\Users\me\workspace\jsonpathexperiments\settings.gradle'.
Projects loaded. Root project using build file 'C:\Users\me\workspace\jsonpathexperiments\build.gradle'.
Included projects: [root project 'jsonpathexperiments']
Evaluating root project 'jsonpathexperiments' using build file 'C:\Users\me\workspace\jsonpathexperiments\build.gradle'.
Creating new cache for metadata-1.1/results, path C:\Users\me\.gradle\caches\transforms-1\metadata-1.1\results.bin, access org.gradle.cache.internal.DefaultCacheAccess@e94b0a
Creating new cache for metadata-2.23/module-metadata, path C:\Users\me\.gradle\caches\modules-2\metadata-2.23\module-metadata.bin, access org.gradle.cache.internal.DefaultCacheAccess@2b9581b1
Creating new cache for metadata-2.23/artifact-at-repository, path C:\Users\me\.gradle\caches\modules-2\metadata-2.23\artifact-at-repository.bin, access org.gradle.cache.internal.DefaultCacheAccess@2b9581b1
Task :jmh Last added: null
All projects evaluated.
Selected primary task 'jmh' from project :
Creating new cache for annotation-processors, path C:\Users\me\workspace\jsonpathexperiments\.gradle\4.1\fileContent\annotation-processors.bin, access org.gradle.cache.internal.DefaultCacheAccess@668b224a
Tasks to be executed: [task ':compileJava', task ':processResources', task ':classes', task ':compileTestJava', task ':processTestResources', task ':testClasses', task ':compileJmhJava', task ':processJmhResources', task ':jmhClasses', task ':jmhRunBytecodeGenerator', task ':jmhCompileGeneratedClasses', task ':jmhJar', task ':jmh']
Creating new cache for resourceHashesCache, path C:\Users\me\workspace\jsonpathexperiments\.gradle\4.1\fileHashes\resourceHashesCache.bin, access org.gradle.cache.internal.DefaultCacheAccess@4deb2494
Invalidating in-memory cache of C:\Users\me\workspace\jsonpathexperiments\.gradle\4.1\fileHashes\resourceHashesCache.bin
Creating new cache for fileSnapshots, path C:\Users\me\workspace\jsonpathexperiments\.gradle\4.1\taskHistory\fileSnapshots.bin, access org.gradle.cache.internal.DefaultCacheAccess@2ba893c0
Creating new cache for taskHistory, path C:\Users\me\workspace\jsonpathexperiments\.gradle\4.1\taskHistory\taskHistory.bin, access org.gradle.cache.internal.DefaultCacheAccess@2ba893c0
:compileJava (Thread[Task worker for ':',5,main]) started.
:compileJava
Putting task artifact state for task ':compileJava' into context took 0.001 secs.
Executing task ':compileJava' (up-to-date check took 0.027 secs) due to:
  Output property 'destinationDir' file C:\Users\me\workspace\jsonpathexperiments\build\classes\java\main has changed.
  Output property 'destinationDir' file C:\Users\me\workspace\jsonpathexperiments\build\classes\java\main\experiments has been removed.
  Output property 'destinationDir' file C:\Users\me\workspace\jsonpathexperiments\build\classes\java\main\experiments\JsonPathExperiments$1.class has been removed.
All input files are considered out-of-date for incremental task ':compileJava'.
Compiling with JDK Java compiler API.
:compileJava (Thread[Task worker for ':',5,main]) completed. Took 0.136 secs.
:processResources (Thread[Task worker for ':',5,main]) started.
:processResources
Putting task artifact state for task ':processResources' into context took 0.0 secs.
Executing task ':processResources' (up-to-date check took 0.002 secs) due to:
  Output property 'destinationDir' file C:\Users\me\workspace\jsonpathexperiments\build\resources\main has changed.
  Output property 'destinationDir' file C:\Users\me\workspace\jsonpathexperiments\build\resources\main\store.json has been removed.
  Output property 'destinationDir' file C:\Users\me\workspace\jsonpathexperiments\build\resources\main\store2.json has been removed.
:processResources (Thread[Task worker for ':',5,main]) completed. Took 0.026 secs.
:classes (Thread[Task worker for ':',5,main]) started.
:classes
Skipping task ':classes' as it has no actions.
:classes (Thread[Task worker for ':',5,main]) completed. Took 0.001 secs.
:compileTestJava (Thread[Task worker for ':',5,main]) started.
:compileTestJava
Putting task artifact state for task ':compileTestJava' into context took 0.0 secs.
:compileTestJava NO-SOURCE
:compileTestJava (Thread[Task worker for ':',5,main]) completed. Took 0.003 secs.
:processTestResources (Thread[Task worker for ':',5,main]) started.
:processTestResources
Putting task artifact state for task ':processTestResources' into context took 0.0 secs.
file or directory 'C:\Users\me\workspace\jsonpathexperiments\src\test\resources', not found
Skipping task ':processTestResources' as it has no source files and no previous output files.
:processTestResources NO-SOURCE
:processTestResources (Thread[Task worker for ':',5,main]) completed. Took 0.002 secs.
:testClasses (Thread[Task worker for ':',5,main]) started.
:testClasses
Skipping task ':testClasses' as it has no actions.
:testClasses UP-TO-DATE
:testClasses (Thread[Task worker for ':',5,main]) completed. Took 0.001 secs.
:compileJmhJava (Thread[Task worker for ':' Thread 7,5,main]) started.
:compileJmhJava
Putting task artifact state for task ':compileJmhJava' into context took 0.0 secs.
Executing task ':compileJmhJava' (up-to-date check took 0.023 secs) due to:
  Output property 'destinationDir' file C:\Users\me\workspace\jsonpathexperiments\build\classes\java\jmh has changed.
  Output property 'destinationDir' file C:\Users\me\workspace\jsonpathexperiments\build\classes\java\jmh\jsonpath has been removed.
  Output property 'destinationDir' file C:\Users\me\workspace\jsonpathexperiments\build\classes\java\jmh\jsonpath\JsonPathVsPojoBenchmark.class has been removed.
All input files are considered out-of-date for incremental task ':compileJmhJava'.
Compiling with JDK Java compiler API.
:compileJmhJava (Thread[Task worker for ':' Thread 7,5,main]) completed. Took 0.103 secs.
:processJmhResources (Thread[Task worker for ':' Thread 7,5,main]) started.
:processJmhResources
Putting task artifact state for task ':processJmhResources' into context took 0.0 secs.
file or directory 'C:\Users\me\workspace\jsonpathexperiments\src\jmh\resources', not found
file or directory 'C:\Users\me\workspace\jsonpathexperiments\src\jmh\resources', not found
Skipping task ':processJmhResources' as it has no source files and no previous output files.
:processJmhResources NO-SOURCE
:processJmhResources (Thread[Task worker for ':' Thread 7,5,main]) completed. Took 0.002 secs.
:jmhClasses (Thread[Task worker for ':' Thread 7,5,main]) started.
:jmhClasses
Skipping task ':jmhClasses' as it has no actions.
:jmhClasses (Thread[Task worker for ':' Thread 7,5,main]) completed. Took 0.001 secs.
:jmhRunBytecodeGenerator (Thread[Task worker for ':' Thread 7,5,main]) started.
:jmhRunBytecodeGenerator
Putting task artifact state for task ':jmhRunBytecodeGenerator' into context took 0.0 secs.
Executing task ':jmhRunBytecodeGenerator' (up-to-date check took 0.026 secs) due to:
  Input property 'testClasses' file C:\Users\me\workspace\jsonpathexperiments\build\classes\java\test has changed.
  Input property 'testClasses' file C:\Users\me\workspace\jsonpathexperiments\build\classes\java\test\LibraryTest.class has been removed.
  Input property 'testRuntimeClasspath' file C:\Users\me\workspace\jsonpathexperiments\build\classes\java\test has changed.
Processing 1 classes from C:\Users\me\workspace\jsonpathexperiments\build\classes\java\jmh with "reflection" generator
Writing out Java source to C:\Users\me\workspace\jsonpathexperiments\build\jmh-generated-sources and resources to C:\Users\me\workspace\jsonpathexperiments\build\jmh-generated-classes
:jmhRunBytecodeGenerator (Thread[Task worker for ':' Thread 7,5,main]) completed. Took 0.07 secs.
:jmhCompileGeneratedClasses (Thread[Task worker for ':' Thread 7,5,main]) started.
:jmhCompileGeneratedClasses
Putting task artifact state for task ':jmhCompileGeneratedClasses' into context took 0.0 secs.
Executing task ':jmhCompileGeneratedClasses' (up-to-date check took 0.007 secs) due to:
  Input property 'classpath' file C:\Users\me\workspace\jsonpathexperiments\build\classes\java\test\LibraryTest.class has been removed.
  Input property 'classpath' file C:\Users\me\.gradle\caches\modules-2\files-2.1\junit\junit\4.12\2973d150c0dc1fefe998f834810d68f278ea58ec\junit-4.12.jar has been added.
  Input property 'classpath' file C:\Users\me\.gradle\caches\modules-2\files-2.1\org.hamcrest\hamcrest-core\1.3\42a25dc3219429f0e5d060061f71acb49bf010a0\hamcrest-core-1.3.jar has changed.
Compiling with JDK Java compiler API.
:jmhCompileGeneratedClasses (Thread[Task worker for ':' Thread 7,5,main]) completed. Took 0.252 secs.
:jmhJar (Thread[Task worker for ':' Thread 7,5,main]) started.
:jmhJar
Putting task artifact state for task ':jmhJar' into context took 0.0 secs.
Executing task ':jmhJar' (up-to-date check took 0.027 secs) due to:
  Output property 'archivePath' file C:\Users\me\workspace\jsonpathexperiments\build\libs\jsonpathexperiments-jmh.jar has changed.
:jmhJar (Thread[Task worker for ':' Thread 7,5,main]) completed. Took 0.405 secs.
:jmh (Thread[Task worker for ':' Thread 7,5,main]) started.
:jmh
Putting task artifact state for task ':jmh' into context took 0.0 secs.
Executing task ':jmh' (up-to-date check took 0.0 secs) due to:
  Task has not declared any outputs.
:jmh FAILED
:jmh (Thread[Task worker for ':' Thread 7,5,main]) completed. Took 0.018 secs.

FAILURE: Build failed with an exception.

* What went wrong:
Execution failed for task ':jmh'.
> A failure occurred while executing me.champeau.gradle.IsolatedRunner
   > Error during execution of benchmarks

* Try:
Run with --debug option to get more log output.

* Exception is:
org.gradle.api.tasks.TaskExecutionException: Execution failed for task ':jmh'.
	at org.gradle.api.internal.tasks.execution.ExecuteActionsTaskExecuter.executeActions(ExecuteActionsTaskExecuter.java:100)
	at org.gradle.api.internal.tasks.execution.ExecuteActionsTaskExecuter.execute(ExecuteActionsTaskExecuter.java:70)
	at org.gradle.api.internal.tasks.execution.SkipUpToDateTaskExecuter.execute(SkipUpToDateTaskExecuter.java:63)
	at org.gradle.api.internal.tasks.execution.ResolveTaskOutputCachingStateExecuter.execute(ResolveTaskOutputCachingStateExecuter.java:54)
	at org.gradle.api.internal.tasks.execution.ValidatingTaskExecuter.execute(ValidatingTaskExecuter.java:58)
	at org.gradle.api.internal.tasks.execution.SkipEmptySourceFilesTaskExecuter.execute(SkipEmptySourceFilesTaskExecuter.java:88)
	at org.gradle.api.internal.tasks.execution.ResolveTaskArtifactStateTaskExecuter.execute(ResolveTaskArtifactStateTaskExecuter.java:52)
	at org.gradle.api.internal.tasks.execution.SkipTaskWithNoActionsExecuter.execute(SkipTaskWithNoActionsExecuter.java:52)
	at org.gradle.api.internal.tasks.execution.SkipOnlyIfTaskExecuter.execute(SkipOnlyIfTaskExecuter.java:54)
	at org.gradle.api.internal.tasks.execution.ExecuteAtMostOnceTaskExecuter.execute(ExecuteAtMostOnceTaskExecuter.java:43)
	at org.gradle.api.internal.tasks.execution.CatchExceptionTaskExecuter.execute(CatchExceptionTaskExecuter.java:34)
	at org.gradle.execution.taskgraph.DefaultTaskGraphExecuter$EventFiringTaskWorker$1.run(DefaultTaskGraphExecuter.java:248)
	at org.gradle.internal.progress.DefaultBuildOperationExecutor$RunnableBuildOperationWorker.execute(DefaultBuildOperationExecutor.java:336)
	at org.gradle.internal.progress.DefaultBuildOperationExecutor$RunnableBuildOperationWorker.execute(DefaultBuildOperationExecutor.java:328)
	at org.gradle.internal.progress.DefaultBuildOperationExecutor.execute(DefaultBuildOperationExecutor.java:197)
	at org.gradle.internal.progress.DefaultBuildOperationExecutor.run(DefaultBuildOperationExecutor.java:107)
	at org.gradle.execution.taskgraph.DefaultTaskGraphExecuter$EventFiringTaskWorker.execute(DefaultTaskGraphExecuter.java:241)
	at org.gradle.execution.taskgraph.DefaultTaskGraphExecuter$EventFiringTaskWorker.execute(DefaultTaskGraphExecuter.java:230)
	at org.gradle.execution.taskgraph.DefaultTaskPlanExecutor$TaskExecutorWorker.processTask(DefaultTaskPlanExecutor.java:124)
	at org.gradle.execution.taskgraph.DefaultTaskPlanExecutor$TaskExecutorWorker.access$200(DefaultTaskPlanExecutor.java:80)
	at org.gradle.execution.taskgraph.DefaultTaskPlanExecutor$TaskExecutorWorker$1.execute(DefaultTaskPlanExecutor.java:105)
	at org.gradle.execution.taskgraph.DefaultTaskPlanExecutor$TaskExecutorWorker$1.execute(DefaultTaskPlanExecutor.java:99)
	at org.gradle.execution.taskgraph.DefaultTaskExecutionPlan.execute(DefaultTaskExecutionPlan.java:625)
	at org.gradle.execution.taskgraph.DefaultTaskExecutionPlan.executeWithTask(DefaultTaskExecutionPlan.java:580)
	at org.gradle.execution.taskgraph.DefaultTaskPlanExecutor$TaskExecutorWorker.run(DefaultTaskPlanExecutor.java:99)
	at org.gradle.internal.concurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:63)
	at org.gradle.internal.concurrent.ManagedExecutorImpl$1.run(ManagedExecutorImpl.java:46)
	at org.gradle.internal.concurrent.ThreadFactoryImpl$ManagedThreadRunnable.run(ThreadFactoryImpl.java:55)
Caused by: org.gradle.workers.internal.DefaultWorkerExecutor$WorkExecutionException: A failure occurred while executing me.champeau.gradle.IsolatedRunner
	at org.gradle.workers.internal.DefaultWorkerExecutor$2.waitForCompletion(DefaultWorkerExecutor.java:156)
	at org.gradle.internal.work.DefaultAsyncWorkTracker.waitForItemsAndGatherFailures(DefaultAsyncWorkTracker.java:99)
	at org.gradle.internal.work.DefaultAsyncWorkTracker.access$000(DefaultAsyncWorkTracker.java:34)
	at org.gradle.internal.work.DefaultAsyncWorkTracker$2.run(DefaultAsyncWorkTracker.java:83)
	at org.gradle.internal.work.DefaultWorkerLeaseService.withoutLocks(DefaultWorkerLeaseService.java:196)
	at org.gradle.internal.work.DefaultWorkerLeaseService.withoutProjectLock(DefaultWorkerLeaseService.java:145)
	at org.gradle.internal.work.DefaultAsyncWorkTracker.waitForCompletion(DefaultAsyncWorkTracker.java:79)
	at org.gradle.api.internal.tasks.execution.ExecuteActionsTaskExecuter$1.run(ExecuteActionsTaskExecuter.java:130)
	at org.gradle.internal.progress.DefaultBuildOperationExecutor$RunnableBuildOperationWorker.execute(DefaultBuildOperationExecutor.java:336)
	at org.gradle.internal.progress.DefaultBuildOperationExecutor$RunnableBuildOperationWorker.execute(DefaultBuildOperationExecutor.java:328)
	at org.gradle.internal.progress.DefaultBuildOperationExecutor.execute(DefaultBuildOperationExecutor.java:197)
	at org.gradle.internal.progress.DefaultBuildOperationExecutor.run(DefaultBuildOperationExecutor.java:107)
	at org.gradle.api.internal.tasks.execution.ExecuteActionsTaskExecuter.executeAction(ExecuteActionsTaskExecuter.java:111)
	at org.gradle.api.internal.tasks.execution.ExecuteActionsTaskExecuter.executeActions(ExecuteActionsTaskExecuter.java:92)
	... 27 more
Caused by: org.gradle.api.GradleException: Error during execution of benchmarks
	at me.champeau.gradle.IsolatedRunner.run(IsolatedRunner.java:40)
	at org.gradle.workers.internal.WorkerServer.execute(WorkerServer.java:31)
	at org.gradle.workers.internal.WorkerDaemonServer.execute(WorkerDaemonServer.java:38)
	at org.gradle.workers.internal.WorkerDaemonServer.execute(WorkerDaemonServer.java:25)
	at org.gradle.process.internal.worker.request.WorkerAction.run(WorkerAction.java:98)
	at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
	at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
	at org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:146)
	at org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:128)
	at org.gradle.internal.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:404)
	... 3 more
Caused by: org.openjdk.jmh.runner.RunnerException: ERROR: Exception while trying to acquire the JMH lock (C:\Windows\/jmh.lock): Access is denied, exiting. Use -Djmh.ignoreLock=true to forcefully continue.
	at org.openjdk.jmh.runner.Runner.run(Runner.java:213)
	at me.champeau.gradle.IsolatedRunner.run(IsolatedRunner.java:38)
	... 12 more


* Get more help at https://help.gradle.org

BUILD FAILED in 1s
7 actionable tasks: 7 executed

(Stefan Oehme) #2

Can you please provide a small example project? That should help narrow the issue down.


(davidmichaelkarr) #3

I’ve attached a project zip file. I hope it’s useful in this form.
jsonpathexperiments.zip (60.1 KB)


(Stefan Oehme) #4

I imported the project into Buildship 2.1.2 and the benchmark runs fine. I’m on MacOS though, so there might still be a difference. Maybe there is some file lock that JMH didn’t clean up on a previous run. Can you kill all daemons and start it from Buildship again?


(davidmichaelkarr) #5

Killed all daemons. Ran test. Same result.

Note that I created an issue for the plugin for this, and someone (not the plugin author) indicated that they see the same issue using Gradle 4.1, but when they move back to Gradle 4.0.2, it doesn’t fail. I haven’t tried that myself yet.


(Alexander Orlov) #6

Same thing over here, you might want to watch https://github.com/melix/jmh-gradle-plugin/issues/105