Plugin appears to eat stdout/stderr from git and probably other CLI tools

We've been noticing problems with the gitflow-maven-plugin failing at various stages as it tries to push to remote, both in the feature-finish and release-finish goals. When that happens, there's nothing useful from git in the logs to troubleshoot why the git command failed because git is provided the "--quiet" option. It'd be good to add a goal/plugin parameter to skip adding this option to troubleshoot git command failures.

From the Git documentation

--quiet Suppress all output, including the listing of updated refs, unless an error occurs. Progress is not reported to the standard error stream.

Try to use with -Dverbose to see internal commands outputs.

The plugin is eating stdout/stderr from git (and probably other CLI tools as well) even with "-Dverbose=true" when we tried it. So it is unclear why git pushes are intermittently failing. We're seeing this across the board. Pushes randomly fail at different stages across builds. To work around it, we have resorted to running the plugin from the CLI by tweaking its options based on the failure. For example:

mvn -X -e -B gitflow:release-finish -DpushRemote=true -DskipTestProject=true
mvn -X -e -B gitflow:release-finish -DpushRemote=true -DskipTestProject=true -DskipTag=true (if the release tag was already pushed)

We'd like to avoid this and only allow running it from CI/CD pipelines. Do you have any recommendations on how to further troubleshoot it? Thanks!

@savitha-atg Which error do you get exactly? Can you include build log?

For me it is working fine. For example, if git push fails during plugin execution then the maven build fails with error from the git command, even w/o enabled verbose.

Here's a snippet of the build log with "-Dverbose=true". Notice how "git push --quiet -u origin release/0.231" fails towards the end, but there's nothing from git showing why it failed.

You're right about the "--quiet" option though. I forked the source code and removed the "--quiet" option to git from everywhere, but that didn't provide any additional logging either. It appears that the plugin is eating stdout/stderr from git and probably all other CLI tools. I've updated the ticket to reflect that.

Last but not least, we think the error is happening because of having a dirty workspace directory on the Jenkins runner before starting the build. Presumably there's a conflict that's preventing git from performing the merge? Deleting the workspace directory before starting the build fixed the issue.


+ mvn -e -X -s /home/jenkins/agent/workspace/nexus_develop@tmp/config15901973300788661943tmp -B gitflow:release-start -DpushRemote=true -Dverbose=true
Apache Maven 3.6.2 (40f52333136460af0dc0d7232c0dc0bcf0d9e117; 2019-08-27T15:06:16Z)
Maven home: /home/jenkins/agent/tools/hudson.tasks.Maven_MavenInstallation/maven-3.6.2
Java version: 11.0.4, vendor: Oracle Corporation, runtime: /usr/local/openjdk-11
Default locale: en, platform encoding: UTF-8
OS name: "linux", version: "5.4.120+", arch: "amd64", family: "unix"
...
[DEBUG] Configuring mojo com.amashchenko.maven.plugin:gitflow-maven-plugin:1.14.0:release-start from plugin realm ClassRealm[plugin>com.amashchenko.maven.plugin:gitflow-maven-plugin:1.14.0, parent: jdk.internal.loader.ClassLoaders$AppClassLoader@4b85612c]
[DEBUG] Configuring mojo 'com.amashchenko.maven.plugin:gitflow-maven-plugin:1.14.0:release-start' with basic configurator -->
[DEBUG]   (f) allowSnapshots = false
[DEBUG]   (f) commitDevelopmentVersionAtStart = false
[DEBUG]   (f) commitMessages = com.amashchenko.maven.plugin.gitflow.CommitMessages@794240e2
[DEBUG]   (f) digitsOnlyDevVersion = false
[DEBUG]   (f) fetchRemote = true
[DEBUG]   (s) versionTagPrefix = v
[DEBUG]   (f) gitFlowConfig = com.amashchenko.maven.plugin.gitflow.GitFlowConfig@68dfda77
[DEBUG]   (f) gpgSignCommit = false
[DEBUG]   (f) installProject = false
[DEBUG]   (f) mavenSession = org.apache.maven.execution.MavenSession@50cdfafa
[DEBUG]   (f) pushRemote = true
[DEBUG]   (f) sameBranchName = false
[DEBUG]   (f) settings = org.apache.maven.execution.SettingsAdapter@2e952845
[DEBUG]   (f) tychoBuild = false
[DEBUG]   (f) useSnapshotInRelease = false
[DEBUG]   (f) verbose = true
[DEBUG]   (f) versionsForceUpdate = false
[DEBUG] -- end configuration --
[DEBUG] git config gitflow.branch.master master
[DEBUG] git config gitflow.branch.develop develop
[DEBUG] git config gitflow.prefix.feature feature/
[DEBUG] git config gitflow.prefix.release release/
[DEBUG] git config gitflow.prefix.hotfix hotfix/
[DEBUG] git config gitflow.prefix.support support/
[DEBUG] git config gitflow.prefix.versiontag v
[DEBUG] git config gitflow.origin origin
[INFO] Checking for uncommitted changes.
[DEBUG] git diff --no-ext-diff --ignore-submodules --quiet --exit-code
[DEBUG] git diff-index --cached --quiet --ignore-submodules HEAD --
[DEBUG] git for-each-ref --count=1 --format="%(refname:short)" refs/heads/release/**
[DEBUG] git show-ref --verify --quiet refs/heads/develop
[INFO] Fetching remote branch 'origin develop'.
[DEBUG] git fetch --quiet origin develop
[INFO] Comparing local branch 'develop' with remote 'origin/develop'.
[DEBUG] git rev-list --left-right --count develop...origin/develop
0   0
[INFO] Checking out 'develop' branch.
[DEBUG] git checkout develop
[INFO] Checking for SNAPSHOT versions in dependencies.
...
[INFO] Committing changes.
[DEBUG] git commit -a -m Update versions for release
[release/0.231 cb86091e] Update versions for release
 1 file changed, 1 insertion(+), 1 deletion(-)
[INFO] Pushing 'release/0.231' branch to 'origin'.
[DEBUG] git push --quiet -u origin release/0.231
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time:  29.996 s
[INFO] Finished at: 2022-01-13T16:14:26Z
[INFO] ------------------------------------------------------------------------
[ERROR] Failed to execute goal com.amashchenko.maven.plugin:gitflow-maven-plugin:1.14.0:release-start (default-cli) on project nexus: MojoFailureException -> [Help 1]
org.apache.maven.lifecycle.LifecycleExecutionException: Failed to execute goal com.amashchenko.maven.plugin:gitflow-maven-plugin:1.14.0:release-start (default-cli) on project nexus: 
    at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:215)
    at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:156)
    at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:148)
    at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject (LifecycleModuleBuilder.java:117)
    at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject (LifecycleModuleBuilder.java:81)
    at org.apache.maven.lifecycle.internal.builder.singlethreaded.SingleThreadedBuilder.build (SingleThreadedBuilder.java:56)
    at org.apache.maven.lifecycle.internal.LifecycleStarter.execute (LifecycleStarter.java:128)
    at org.apache.maven.DefaultMaven.doExecute (DefaultMaven.java:305)
    at org.apache.maven.DefaultMaven.doExecute (DefaultMaven.java:192)
    at org.apache.maven.DefaultMaven.execute (DefaultMaven.java:105)
    at org.apache.maven.cli.MavenCli.execute (MavenCli.java:956)
    at org.apache.maven.cli.MavenCli.doMain (MavenCli.java:288)
    at org.apache.maven.cli.MavenCli.main (MavenCli.java:192)
    at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0 (Native Method)
    at jdk.internal.reflect.NativeMethodAccessorImpl.invoke (NativeMethodAccessorImpl.java:62)
    at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke (DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke (Method.java:566)
    at org.codehaus.plexus.classworlds.launcher.Launcher.launchEnhanced (Launcher.java:282)
    at org.codehaus.plexus.classworlds.launcher.Launcher.launch (Launcher.java:225)
    at org.codehaus.plexus.classworlds.launcher.Launcher.mainWithExitCode (Launcher.java:406)
    at org.codehaus.plexus.classworlds.launcher.Launcher.main (Launcher.java:347)
Caused by: org.apache.maven.plugin.MojoFailureException: 
    at com.amashchenko.maven.plugin.gitflow.AbstractGitFlowMojo.executeCommand (AbstractGitFlowMojo.java:1170)
    at com.amashchenko.maven.plugin.gitflow.AbstractGitFlowMojo.executeGitCommand (AbstractGitFlowMojo.java:1099)
    at com.amashchenko.maven.plugin.gitflow.AbstractGitFlowMojo.gitPush (AbstractGitFlowMojo.java:955)
    at com.amashchenko.maven.plugin.gitflow.GitFlowReleaseStartMojo.execute (GitFlowReleaseStartMojo.java:253)
    at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo (DefaultBuildPluginManager.java:137)
    at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:210)
    at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:156)
    at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:148)
    at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject (LifecycleModuleBuilder.java:117)
    at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject (LifecycleModuleBuilder.java:81)
    at org.apache.maven.lifecycle.internal.builder.singlethreaded.SingleThreadedBuilder.build (SingleThreadedBuilder.java:56)
    at org.apache.maven.lifecycle.internal.LifecycleStarter.execute (LifecycleStarter.java:128)
    at org.apache.maven.DefaultMaven.doExecute (DefaultMaven.java:305)
    at org.apache.maven.DefaultMaven.doExecute (DefaultMaven.java:192)
    at org.apache.maven.DefaultMaven.execute (DefaultMaven.java:105)
    at org.apache.maven.cli.MavenCli.execute (MavenCli.java:956)
    at org.apache.maven.cli.MavenCli.doMain (MavenCli.java:288)
    at org.apache.maven.cli.MavenCli.main (MavenCli.java:192)
    at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0 (Native Method)
    at jdk.internal.reflect.NativeMethodAccessorImpl.invoke (NativeMethodAccessorImpl.java:62)
    at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke (DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke (Method.java:566)
    at org.codehaus.plexus.classworlds.launcher.Launcher.launchEnhanced (Launcher.java:282)
    at org.codehaus.plexus.classworlds.launcher.Launcher.launch (Launcher.java:225)
    at org.codehaus.plexus.classworlds.launcher.Launcher.mainWithExitCode (Launcher.java:406)
    at org.codehaus.plexus.classworlds.launcher.Launcher.main (Launcher.java:347)
[ERROR] 
[ERROR] 
[ERROR] For more information about the errors and possible solutions, please read the following articles:
[ERROR] [Help 1] http://cwiki.apache.org/confluence/display/MAVEN/MojoFailureException```

Seems like there is no output in standard output or error streams. Does it happen only in CI environment? Maybe output is redirected somewhere?

Do you know why it is actually fails? Can you try running git push directly to see does it print something into the console.

Yes, it happens only in the CI environment. That's a good suggestion to see if out/err are being redirected or sent to /dev/null. I'll check that and report back.

I don't know why it actually fails, but my guess is that the Jenkins workspace directory is dirty, which causes a merge conflict on push. After adding a step to delete the workspace before the build, we've been seeing pipelines pass consistently.

Here's a snippet from a local run if that helps:

mvn -e -X gitflow:release-finish -DpushRemote=true -DskipTestProject=true -DskipTag -DskipTestProject

Apache Maven 3.8.4 (9b656c72d54e5bacbed989b64718c159fe39b537)
Maven home: /usr/local/Cellar/maven/3.8.4/libexec
Java version: 11.0.11, vendor: AdoptOpenJDK, runtime: /Library/Java/JavaVirtualMachines/adoptopenjdk-11.jdk/Contents/Home
Default locale: en_US, platform encoding: UTF-8
OS name: "mac os x", version: "11.1", arch: "x86_64", family: "mac"
...

mvn -e -X gitflow:release-finish -DpushRemote=true -DskipTestProject=true -DskipTag -DskipTestProject
...

INFO] --- gitflow-maven-plugin:1.14.0:release-finish (default-cli) @ nexus ---
...
[INFO] Checking for uncommitted changes.
[DEBUG] git diff --no-ext-diff --ignore-submodules --quiet --exit-code
[DEBUG] git diff-index --cached --quiet --ignore-submodules HEAD --
[DEBUG] git for-each-ref --format="%(refname:short)" refs/heads/release/**
"release/0.231"
[INFO] Checking out 'release/0.231' branch.
[DEBUG] git checkout release/0.231
Your branch is up to date with 'origin/release/0.231'.
[INFO] Checking for SNAPSHOT versions in dependencies.
[INFO] Fetching remote branch 'origin release/0.231'.
[DEBUG] git fetch --quiet origin release/0.231
[INFO] Comparing local branch 'release/0.231' with remote 'origin/release/0.231'.
[DEBUG] git rev-list --left-right --count release/0.231...origin/release/0.231
0       0
[DEBUG] git show-ref --verify --quiet refs/heads/develop
[INFO] Fetching remote branch 'origin develop'.
[DEBUG] git fetch --quiet origin develop
[INFO] Comparing local branch 'develop' with remote 'origin/develop'.
[DEBUG] git rev-list --left-right --count develop...origin/develop
0       0
[DEBUG] git show-ref --verify --quiet refs/heads/master
[INFO] Fetching remote branch 'origin master'.
[DEBUG] git fetch --quiet origin master
[INFO] Comparing local branch 'master' with remote 'origin/master'.
[DEBUG] git rev-list --left-right --count master...origin/master
0       0
[INFO] Checking out 'release/0.231' branch.
[DEBUG] git checkout release/0.231
Your branch is up to date with 'origin/release/0.231'.
[INFO] Checking out 'master' branch.
[DEBUG] git checkout master
Your branch is up to date with 'origin/master'.
[INFO] Merging (--no-ff) 'release/0.231' branch.
[DEBUG] git merge --no-ff  release/0.231
Already up to date.
[INFO] Checking out 'develop' branch.
[DEBUG] git checkout develop
Your branch is up to date with 'origin/develop'.
[INFO] Merging (--no-ff) 'release/0.231' branch.
[DEBUG] git merge --no-ff  release/0.231
Merge made by the 'recursive' strategy.
 pom.xml | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)
[INFO] Updating version(s) to '0.232-SNAPSHOT'.
[DEBUG] mvn org.codehaus.mojo:versions-maven-plugin:set   -DnewVersion=0.232-SNAPSHOT -DgenerateBackupPoms=false

Apache Maven 3.8.4 (9b656c72d54e5bacbed989b64718c159fe39b537)
Maven home: /usr/local/Cellar/maven/3.8.4/libexec
Java version: 11.0.11, vendor: AdoptOpenJDK, runtime: /Library/Java/JavaVirtualMachines/adoptopenjdk-11.jdk/Contents/Home
Default locale: en_US, platform encoding: UTF-8
OS name: "mac os x", version: "11.1", arch: "x86_64", family: "mac"
...
[INFO] Committing changes.
[DEBUG] git commit -a -m Update for next development version
[develop bfb69eac] Update for next development version
 1 file changed, 1 insertion(+), 1 deletion(-)
[INFO] Pushing 'master' branch to 'origin'.
[DEBUG] git push --quiet -u origin master
[INFO] Pushing 'develop' branch to 'origin'.
[DEBUG] git push --quiet -u origin develop
[INFO] Deleting remote branch 'release/0.231' from 'origin'.
[DEBUG] git push --delete origin release/0.231
[INFO] Deleting 'release/0.231' branch.
[DEBUG] git branch -d release/0.231
Deleted branch release/0.231 (was 319453c2).

Successful build is useless in this case. Try to deliberately create some merge conflicts or change origin url for example, and run locally to see if you get errors in console.

Sorry for the delayed response, but it took some time to find a consistent set of repro steps. Git's stdout/stderr were not being properly output in the CI system because of the way we were invoking mvn before; so the issue, as written, may be ignored. We've fixed that now, and it shows the problem as being due to a git merge conflict.

Steps:

Created a feature branch off of develop
Merged it into develop
- dev image was built and deployed to dev environment
Started a release from the develop branch
- A release/1.0.1 branch was created by the release-start goal of gitflow-maven-plugin
- release image was built and deployed to staging environment
Created another feature branch off of latest develop
Merged it into develop
- New dev image was built and deployed to dev environment
Started a release from the develop branch
- NOTE: the gitflow-maven-plugin reused release branch release/1.0.1 - the pom.xml in develop hasn’t been revved up for the next version because the release-finish goal hasn’t run yet (i.e. no release was done from this branch yet).
- Merge (--no-ff) to release/1.0.1 failed with conflict because the branch already existed on remote with divergent history

[INFO] [jenkins-event-spy] Generated /home/jenkins/agent/workspace/p-service-github-actions_develop@tmp/withMaven861311bb/maven-spy-20220126-002631-1810320265126289196500.log
[INFO] Committing changes.
[DEBUG] git commit -a -m Update versions for release
[release/1.0.1 1554b27] Update versions for release
 1 file changed, 1 insertion(+), 1 deletion(-)
[INFO] Pushing 'release/1.0.1' branch to 'origin'.
[DEBUG] git push --quiet -u origin release/1.0.1
[INFO] ------------------------------------------------------------------------
[INFO] Reactor Summary for Noop Service GitHub Actions Complete 1.0.1-SNAPSHOT:
[INFO] 
[INFO] Noop Service GitHub Actions Complete ............... FAILURE [ 26.345 s]
[INFO] Noop Service GitHub Actions Model .................. SKIPPED
[INFO] Noop Service GitHub Actions Client ................. SKIPPED
[INFO] Noop Service GitHub Actions ........................ SKIPPED
[INFO] ------------------------------------------------------------------------
[INFO] BUILD FAILURE
[INFO] ------------------------------------------------------------------------
[INFO] Total time:  31.979 s
[INFO] Finished at: 2022-01-26T00:26:44Z
[INFO] ------------------------------------------------------------------------
[INFO] [jenkins-event-spy] Generated /home/jenkins/agent/workspace/p-service-github-actions_develop@tmp/withMaven861311bb/maven-spy-20220126-002612-811553166438173596379.log
[ERROR] Failed to execute goal com.amashchenko.maven.plugin:gitflow-maven-plugin:1.14.0:release-start (default-cli) on project noop-service-github-actions-complete: To https://github.com/acrisuretechnology/noop-service-github-actions.git
[ERROR]  ! [rejected]        release/1.0.1 -> release/1.0.1 (non-fast-forward)
[ERROR] error: failed to push some refs to 'https://github.com/acrisuretechnology/noop-service-github-actions.git'
[ERROR] hint: Updates were rejected because the tip of your current branch is behind
[ERROR] hint: its remote counterpart. Integrate the remote changes (e.g.
[ERROR] hint: 'git pull ...') before pushing again.
[ERROR] hint: See the 'Note about fast-forwards' in 'git push --help' for details.
[ERROR] -> [Help 1]

It looks to me like the plugin cannot safely support concurrent releases to shared environments. Whenever multiple people do PRs on the same repo at the same time and don’t synchronize its release properly, there’s potential for failures such as the above. Is that right? Or, do you think perhaps we're not using thegitflow-maven-plugin as intended? Thanks!

What do you mean by reused release branch? Currently, only one release branch is supported.

We call the plugin's "release-start" and "release-finish" goals separately via manual CI jobs. At a high-level, the "release-start" goal is intended to deploy to the staging environment, and the "release-finish" goal to the prod environment. However, the current process we're using lacks proper synchronization between members of the team. So it's possible to get into the scenario described above if deployments from dev -> stage -> prod are not completely sequential, i.e. no concurrent releases.

If a PR gets merged into the “develop” branch while a previous release has not been fully completed (i.e. "release-finish" hasn't run on it yet), then the previously created "release" branch is re-used when "release-start" runs again because "develop" hasn't been updated yet for the next version.

aleksandr-m / gitflow-maven-plugin

Plugin appears to eat stdout/stderr from git and probably other CLI tools #325

Steps: