Amedee Van Gasse
Amedee Van Gasse

Reputation: 7634

Jenkins pipeline Warnings Next Generation Plugin: git rev-parse HEAD^{commit} takes a (too) long time

This is the relevant part of the Jenkinsfile:

stage('Static Code Analysis') {
    options {
        timeout(time: 1, unit: 'HOURS')
    }
    steps {
        withMaven(jdk: "${JDK_VERSION}", maven: 'M3', mavenLocalRepo: '.repository') {
            sh 'mvn --no-transfer-progress verify --activate-profiles qa -Dpmd.analysisCache=true'
        }
        recordIssues(tools: [
                checkStyle(),
                pmdParser(),
                spotBugs(useRankAsPriority: true)
        ])
        dependencyCheckPublisher pattern: 'target/dependency-check-report.xml'
    }
}

This is an excerpt from the Jenkins console log:

00:10:26.471  [CheckStyle] Successfully parsed file /home/ubuntu/jenkins/workspace/iText_7_Java_itextcore_develop/target/checkstyle-result.xml
00:10:26.471  [CheckStyle] -> found 0 issues (skipped 0 duplicates)
00:10:26.847  using credential bd100583-6d56-496a-89c0-67e640c2f80e
00:10:27.322  using credential bd100583-6d56-496a-89c0-67e640c2f80e
00:10:26.896   > /usr/bin/git rev-parse HEAD^{commit} # timeout=10
00:10:27.699  using credential bd100583-6d56-496a-89c0-67e640c2f80e
00:10:28.173  using credential bd100583-6d56-496a-89c0-67e640c2f80e
00:10:27.748   > /usr/bin/git rev-parse HEAD^{commit} # timeout=10
00:12:10.218   > /usr/bin/git rev-parse HEAD^{commit} # timeout=10
00:25:35.352  [CheckStyle] Post processing issues on 'jenkins-node-aws' with source code encoding 'UTF-8'
00:25:35.352  [CheckStyle] Creating SCM blamer to obtain author and commit information for affected files
00:25:35.352  [CheckStyle] -> Git blamer successfully created in working tree '/home/ubuntu/jenkins/workspace/iText_7_Java_itextcore_develop'
00:25:35.352  [CheckStyle] Creating SCM miner to obtain statistics for affected repository files
00:25:35.352  [CheckStyle] -> Git miner successfully created in working tree '/home/ubuntu/jenkins/workspace/iText_7_Java_itextcore_develop'
00:25:35.352  [CheckStyle] Resolving file names for all issues in source directory '/home/ubuntu/jenkins/workspace/iText_7_Java_itextcore_develop'
00:25:35.352  [CheckStyle] -> resolved paths in source directory (1238 found, 0 not found)
00:25:35.352  [CheckStyle] Resolving module names from module definitions (build.xml, pom.xml, or Manifest.mf files)
00:25:35.352  [CheckStyle] -> resolved module names for 85004 issues
00:25:35.352  [CheckStyle] Resolving package names (or namespaces) by parsing the affected files
00:25:35.352  [CheckStyle] -> resolved package names of 1238 affected files
00:25:35.352  [CheckStyle] No filter has been set, publishing all 85004 issues
00:25:35.352  [CheckStyle] Creating fingerprints for all affected code blocks to track issues over different builds
00:25:35.352  [CheckStyle] -> created fingerprints for 85004 issues (skipped 0 issues)
00:25:35.352  [CheckStyle] Invoking Git blamer to create author and commit information for 1238 affected files
00:25:35.352  [CheckStyle] GIT_COMMIT env = 'HEAD'
00:25:35.352  [CheckStyle] Git commit ID = '62d4a2abfda51f58acac8f4ce8e799dffcdbfb0a'
00:25:35.352  [CheckStyle] Git working tree = '/home/ubuntu/jenkins/workspace/iText_7_Java_itextcore_develop'
00:25:35.352  [CheckStyle] -> blamed authors of issues in 1238 files
00:25:35.352  [CheckStyle] Blaming of authors took 498 seconds
00:25:35.352  [CheckStyle] Analyzing the commit log of the Git repository '/home/ubuntu/jenkins/workspace/iText_7_Java_itextcore_develop'
00:25:35.352  [CheckStyle] Invoking Git miner to create statistics for all available files
00:25:35.352  [CheckStyle] Git working tree = '/home/ubuntu/jenkins/workspace/iText_7_Java_itextcore_develop'
00:25:35.352  [CheckStyle] -> created statistics for 1238 files
00:25:35.352  [CheckStyle] -> created report for 1238 files in 69 seconds
00:25:35.352  [CheckStyle] Copying affected files to Jenkins' build folder '/var/lib/jenkins/jobs/iText_7_Java/jobs/itextcore/branches/develop/builds/910/files-with-issues'
00:25:35.352  [CheckStyle] -> 1238 copied, 0 not in workspace, 0 not-found, 0 with I/O error
00:28:49.752  [CheckStyle] Using reference build 'iText_7_Java/itextcore/develop #909' to compute new, fixed, and outstanding issues
00:28:49.752  [CheckStyle] Issues delta (vs. reference build): outstanding: 85002, new: 2, fixed: 2
00:28:49.752  [CheckStyle] No quality gates have been set - skipping
00:28:49.752  [CheckStyle] Health report is disabled - skipping
00:28:49.752  [CheckStyle] Created analysis result for 85004 issues (found 2 new issues, fixed 2 issues)
00:28:49.752  [CheckStyle] Attaching ResultAction with ID 'checkstyle' to run 'iText_7_Java/itextcore/develop #910'.

Notice the jump in time stamp from 00:10:27.748 to 00:12:10.218 to 00:25:35.352. I see a similar (although less extreme) jump in time stamps when Jenkins is doing the recordIssues for PMD and SpotBugs.

This takes too long for just running git rev-parse and the delay is unacceptable. 13 minutes of doing absolutely nothing useful. No other jobs were running at the time. What is going on here and how to fix it?

EDIT:

The delay is NOT, and I repeat: NOT in the mvn command. It is in the recordIssues command.

EDIT:

EDIT:

recordIssues is a Jenkins pipeline build step that comes from Warnings Next Generation Plugin. https://www.jenkins.io/doc/pipeline/steps/warnings-ng/#recordissues-record-compiler-warnings-and-static-analysis-results

Upvotes: 3

Views: 1459

Answers (1)

Nick Carpenter
Nick Carpenter

Reputation: 11

I'm not sure this will qualify as an answer but I'm seeing this issue as well and it is, I believe, related to network transfer to the slave.

There is a significant upload that occurs when using the Warnings-NG plugin recordIssues step. I've examined what's changing on the filesystem when this transfer is happening (i.e. when recordIssues appears to be doing nothing) and the only files I see changing are in the Jenkins jarCache folder.

My theory is that the plugin is sending across jar files to cache for local execution on the slave node vs executing on the master. This likely works well when the slave is persistent, not so much when ephemeral.

Also, if I keep my slave node around for a subsequent build the issue goes away; likely because the cache is already populated.

Upvotes: 1

Related Questions