I thought I'd post about an issue I experienced with Gradle while
testing the build/release process in docker.
I use Docker for Windows, which spins up a Hyper-V VM with docker and I
interact with it using the docker CLI in WSL (Windows Subsystem for
Linux). The setup is really neat, because I can use Windows as my main
OS and almost have Linux running inside with almost native performance
without having to use a VM.
A couple of days ago, Docker released 2.1.6.0 for their Docker for
Windows Edge release and the build started hanging.
Basically, I execute the following to build and upload the release for
voting (in the test environment):
gradle prepareVote -PasfTestSvnUsername=test -PasfTestSvnPassword=test
-PasfTestNexusUsername=test -PasfTestNexusPassword=test
-PasfTestGitSourceUsername=test -PasfTestGitSourcePassword=test
-PasfCommitterId=test -PallowUncommittedChanges -Prc=0 -PuseGpgCmd
-Psigning.gnupg.keyName=KEY_ID_GOES_HERE
The build will run, but it will hang forever after the configuration.
Logs here:
2019-11-20T05:01:25.697+0000 [DEBUG]
[org.gradle.internal.operations.DefaultBuildOperationExecutor] Build
operation 'Execute 'allprojects {}' action' completed
2019-11-20T05:01:25.699+0000 [DEBUG]
[org.gradle.internal.operations.DefaultBuildOperationExecutor] Build
operation 'Execute container callback action' started
2019-11-20T05:01:25.701+0000 [DEBUG]
[org.gradle.internal.operations.DefaultBuildOperationExecutor]
Completing Build operation 'Execute container callback action'
2019-11-20T05:01:25.701+0000 [DEBUG]
[org.gradle.internal.operations.DefaultBuildOperationExecutor] Build
operation 'Execute container callback action' completed
2019-11-20T05:01:25.701+0000 [DEBUG]
[org.gradle.internal.operations.DefaultBuildOperationExecutor]
Completing Build operation 'Apply plugin com.github.vlsi.ide to root
project 'calcite-avatica''
2019-11-20T05:01:25.701+0000 [DEBUG]
[org.gradle.internal.operations.DefaultBuildOperationExecutor] Build
operation 'Apply plugin com.github.vlsi.ide to root project
'calcite-avatica'' completed
2019-11-20T05:01:25.702+0000 [DEBUG]
[org.gradle.internal.operations.DefaultBuildOperationExecutor] Build
operation 'Apply plugin com.github.vlsi.crlf to root project
'calcite-avatica'' started
2019-11-20T05:01:25.702+0000 [DEBUG]
[org.gradle.internal.operations.DefaultBuildOperationExecutor]
Completing Build operation 'Apply plugin com.github.vlsi.crlf to root
project 'calcite-avatica''
2019-11-20T05:01:25.702+0000 [DEBUG]
[org.gradle.internal.operations.DefaultBuildOperationExecutor] Build
operation 'Apply plugin com.github.vlsi.crlf to root project
'calcite-avatica'' completed
2019-11-20T05:01:25.703+0000 [DEBUG]
[org.gradle.internal.operations.DefaultBuildOperationExecutor] Build
operation 'Apply plugin com.github.vlsi.gradle-extensions to root
project 'calcite-avatica'' started
2019-11-20T05:01:25.704+0000 [DEBUG]
[org.gradle.internal.operations.DefaultBuildOperationExecutor]
Completing Build operation 'Apply plugin
com.github.vlsi.gradle-extensions to root project 'calcite-avatica''
2019-11-20T05:01:25.704+0000 [DEBUG]
[org.gradle.internal.operations.DefaultBuildOperationExecutor] Build
operation 'Apply plugin com.github.vlsi.gradle-extensions to root
project 'calcite-avatica'' completed
2019-11-20T05:01:25.706+0000 [DEBUG]
[org.gradle.internal.operations.DefaultBuildOperationExecutor] Build
operation 'Apply plugin com.github.vlsi.stage-vote-release to root
project 'calcite-avatica'' started
2019-11-20T05:01:25.728+0000 [DEBUG]
[org.gradle.internal.operations.DefaultBuildOperationExecutor] Build
operation 'Execute container callback action' started
2019-11-20T05:01:25.728+0000 [DEBUG]
[org.gradle.internal.operations.DefaultBuildOperationExecutor]
Completing Build operation 'Execute container callback action'
2019-11-20T05:01:25.728+0000 [DEBUG]
[org.gradle.internal.operations.DefaultBuildOperationExecutor] Build
operation 'Execute container callback action' completed
2019-11-20T05:01:25.728+0000 [DEBUG]
[org.gradle.internal.operations.DefaultBuildOperationExecutor] Build
operation 'Execute container callback action' started
2019-11-20T05:01:25.729+0000 [DEBUG]
[org.gradle.internal.operations.DefaultBuildOperationExecutor]
Completing Build operation 'Execute container callback action'
2019-11-20T05:01:25.729+0000 [DEBUG]
[org.gradle.internal.operations.DefaultBuildOperationExecutor] Build
operation 'Execute container callback action' completed
2019-11-20T05:01:25.729+0000 [DEBUG]
[org.gradle.internal.operations.DefaultBuildOperationExecutor] Build
operation 'Execute container callback action' started
2019-11-20T05:01:25.729+0000 [DEBUG]
[org.gradle.internal.operations.DefaultBuildOperationExecutor]
Completing Build operation 'Execute container callback action'
2019-11-20T05:01:25.729+0000 [DEBUG]
[org.gradle.internal.operations.DefaultBuildOperationExecutor] Build
operation 'Execute container callback action' completed
2019-11-20T05:01:25.730+0000 [DEBUG]
[org.gradle.internal.operations.DefaultBuildOperationExecutor] Build
operation 'Apply plugin org.ajoberstar.grgit to root project
'calcite-avatica'' started
2019-11-20T05:01:25.869+0000 [DEBUG]
[org.eclipse.jgit.internal.storage.file.FileSnapshot]
file=/src/.git/config, create new FileSnapshot: lastRead=2019-11-20
05:01:25.863000000, lastModified=2019-11-20 04:23:05.546426000,
size=349, fileKey=(dev=65,ino=41)
2019-11-20T05:01:25.875+0000 [DEBUG] [org.eclipse.jgit.util.FS] readpipe
[git, --version],/usr/bin
2019-11-20T05:01:25.881+0000 [DEBUG] [org.eclipse.jgit.util.FS] readpipe
may return 'git version 2.17.1'
2019-11-20T05:01:25.881+0000 [DEBUG] [org.eclipse.jgit.util.FS]
remaining output:
2019-11-20T05:01:25.882+0000 [DEBUG] [org.eclipse.jgit.util.FS] readpipe
[git, config, --system, --edit],/usr/bin
2019-11-20T05:01:25.885+0000 [DEBUG] [org.eclipse.jgit.util.FS] readpipe
may return '/etc/gitconfig'
2019-11-20T05:01:25.885+0000 [DEBUG] [org.eclipse.jgit.util.FS]
remaining output:
2019-11-20T05:01:25.887+0000 [DEBUG]
[org.eclipse.jgit.internal.storage.file.FileSnapshot] file=null, size
changed from -1 to 0 bytes
2019-11-20T05:01:25.887+0000 [DEBUG]
[org.eclipse.jgit.util.SystemReader] loading system config
FileBasedConfig[/etc/gitconfig]
2019-11-20T05:01:25.888+0000 [DEBUG]
[org.eclipse.jgit.internal.storage.file.FileSnapshot] file=null, size
changed from -1 to 0 bytes
2019-11-20T05:01:25.888+0000 [DEBUG]
[org.eclipse.jgit.util.SystemReader] loading user config
FileBasedConfig[/root/.gitconfig]
2019-11-20T05:01:25.889+0000 [DEBUG]
[org.eclipse.jgit.internal.storage.file.FileSnapshot]
file=/src/.git/config, create new FileSnapshot: lastRead=2019-11-20
05:01:25.888000000, lastModified=2019-11-20 04:23:05.546426000,
size=349, fileKey=(dev=65,ino=41)
2019-11-20T05:01:25.892+0000 [DEBUG]
[org.eclipse.jgit.internal.storage.file.FileSnapshot]
file=/etc/gitconfig, isRacyClean=false, read=2019-11-20
05:01:25.887000000, lastModified=1970-01-01 00:00:00.000000000,
delta=1574226085887000000 ns, racy<=2500000000 ns
2019-11-20T05:01:25.892+0000 [DEBUG]
[org.eclipse.jgit.internal.storage.file.FileSnapshot]
file=/etc/gitconfig, is unmodified
2019-11-20T05:01:25.892+0000 [DEBUG]
[org.eclipse.jgit.internal.storage.file.FileSnapshot]
file=/root/.gitconfig, isRacyClean=false, read=2019-11-20
05:01:25.888000000, lastModified=1970-01-01 00:00:00.000000000,
delta=1574226085888000000 ns, racy<=2500000000 ns
2019-11-20T05:01:25.892+0000 [DEBUG]
[org.eclipse.jgit.internal.storage.file.FileSnapshot]
file=/root/.gitconfig, is unmodified
2019-11-20T05:01:25.893+0000 [DEBUG]
[org.eclipse.jgit.internal.storage.file.FileSnapshot]
file=/src/.git/config, isRacyClean=false, read=2019-11-20
05:01:25.888000000, lastModified=2019-11-20 04:23:05.546426000,
delta=2300341574000 ns, racy<=2500000000 ns
2019-11-20T05:01:25.893+0000 [DEBUG]
[org.eclipse.jgit.internal.storage.file.FileSnapshot]
file=/src/.git/config, is unmodified
2019-11-20T05:01:35.058+0000 [LIFECYCLE]
[org.gradle.cache.internal.DefaultFileLockManager]
2019-11-20T05:01:35.058+0000 [DEBUG]
[org.gradle.cache.internal.DefaultFileLockManager] Waiting to acquire
shared lock on daemon addresses registry.
2019-11-20T05:01:35.058+0000 [DEBUG]
[org.gradle.cache.internal.DefaultFileLockManager] Lock acquired on
daemon addresses registry.
2019-11-20T05:01:35.058+0000 [DEBUG]
[org.gradle.cache.internal.DefaultFileLockManager] Releasing lock on
daemon addresses registry.
2019-11-20T05:01:35.058+0000 [DEBUG]
[org.gradle.cache.internal.DefaultFileLockManager] Waiting to acquire
shared lock on daemon addresses registry.
2019-11-20T05:01:35.058+0000 [DEBUG]
[org.gradle.cache.internal.DefaultFileLockManager] Lock acquired on
daemon addresses registry.
2019-11-20T05:01:35.058+0000 [DEBUG]
[org.gradle.cache.internal.DefaultFileLockManager] Releasing lock on
daemon addresses registry.
2019-11-20T05:01:45.058+0000 [DEBUG]
[org.gradle.cache.internal.DefaultFileLockManager] Waiting to acquire
shared lock on daemon addresses registry.
2019-11-20T05:01:45.058+0000 [DEBUG]
[org.gradle.cache.internal.DefaultFileLockManager] Lock acquired on
daemon addresses registry.
2019-11-20T05:01:45.058+0000 [DEBUG]
[org.gradle.cache.internal.DefaultFileLockManager] Releasing lock on
daemon addresses registry.
2019-11-20T05:01:45.058+0000 [DEBUG]
[org.gradle.cache.internal.DefaultFileLockManager] Waiting to acquire
shared lock on daemon addresses registry.
2019-11-20T05:01:45.058+0000 [DEBUG]
[org.gradle.cache.internal.DefaultFileLockManager] Lock acquired on
daemon addresses registry.
2019-11-20T05:01:45.058+0000 [DEBUG]
[org.gradle.cache.internal.DefaultFileLockManager] Releasing lock on
daemon addresses registry.
This only happens when I have Avatica on the Windows filesystem and
mount it into the docker container to build. I suspect these changes in
Docker for Windows could be the cause:
- Docker Desktop now supports inotify events on shared filesystems for
Windows file sharing.
- Fixed a cache invalidation bug when a file in a shared volume is
renamed on the host for Windows file sharing.
- Fixed a handle leak when calling Mknod on a shared volume for Windows
file sharing.
- To make VM startup more reliable, Docker Desktop now avoids adding a
Hyper-V NIC to the Windows VM when using Hypervisor sockets for Windows
file sharing (rather than Samba).
I did test a few of the sample gradle projects[1], and they all built
without issue.
The issue only happens when mounting the Avatica source folder in the
Windows filesystem into the docker container. If we clone the git
repository within the docker container, it works correctly, but this
wouldn't really work with using docker-compose to orchestrate the build.
Interestingly, I am able to use touch, rm etc to interact with the
Windows mount within the container and nothing seems to be blocked.
The solution I've found is to downgrade to Docker for Windows 2.1.3.0
(2.1.4.0 and 2.1.5.0 has issues with starting Docker for Windows and are
pretty much unusable).
In Docker for Windows 2.1.3.0, I get this error, but the build works fine:
Starting a Gradle Daemon (subsequent builds will be faster)
locking FileBasedConfig[/root/.gitconfig] failed after 5 retries
> Configure project :
Building Apache Calcite Avatica 1.16.0
Unfortunately, I don't have much time to investigate Gradle's and Docker
for Windows' internals after spending the whole day on this, so this is
all I have.
Framcos
[1] https://github.com/gradle/kotlin-dsl-samples/tree/master/samples
On 20/11/2019 6:11 pm, Vladimir Sitnikov wrote:
I also notice this output at the end, is this a known issue?
Deprecated Gradle features were used in this build, making it incompatible
with Gradle 7.0.
It is.
Also is there an easy way to specify number of threads for build and test
run?
Please find the documentation here:
https://docs.gradle.org/6.0.1/userguide/command_line_interface.html#sec:command_line_performance
and here
https://junit.org/junit5/docs/current/user-guide/#writing-tests-parallel-execution
Vladimir
