Fixing bug where git project is built twice when changes are pushed

13 views
Skip to first unread message

tho...@sondergaard.cc

unread,
Apr 4, 2018, 5:29:02 AM4/4/18
to Jenkins Developers
My project is suffering from a problem where jobs sometimes build the same commit twice. This seems to happen when two or more pushes are made within a short time (by one or more developers).

I think the problem matches one or both of these:

https://issues.jenkins-ci.org/browse/JENKINS-17346
https://issues.jenkins-ci.org/browse/JENKINS-30350

My job is a multi-configuration job configured for pre-build branch merging as describe here: https://plugins.jenkins.io/git#GitPlugin-UsingGit,Jenkinsandpre-buildbranchmerging

My full job config.xml can be found here: https://pastebin.com/BqBUQEpe

I could use some help figuring out why this happens. Here is what I have done so far. I've checked out bitbucket-plugin to start from the trigger. Here, I've drilled down to BitBucketTrigger.onPost() which appears to be where the interesting stuff is happening.

    public void onPost(String triggeredByUser, final String payload) {
       
final String pushBy = triggeredByUser;
        getDescriptor
().queue.execute(new Runnable() {
           
private boolean runPolling() {
               
try {
                   
StreamTaskListener listener = new StreamTaskListener(getLogFile());
                   
try {
                       
PrintStream logger = listener.getLogger();
                       
long start = System.currentTimeMillis();
                        logger
.println("Started on "+ DateFormat.getDateTimeInstance().format(new Date()));
                       
boolean result = SCMTriggerItem.SCMTriggerItems.asSCMTriggerItem(job).poll(listener).hasChanges();
                        logger
.println("Done. Took "+ Util.getTimeSpanString(System.currentTimeMillis()-start));
                       
if(result)
                            logger
.println("Changes found");
                       
else
                            logger
.println("No changes");
                       
return result;
                   
} catch (Error e) {
                        e
.printStackTrace(listener.error("Failed to record SCM polling"));
                        LOGGER
.log(Level.SEVERE,"Failed to record SCM polling",e);
                       
throw e;
                   
} catch (RuntimeException e) {
                        e
.printStackTrace(listener.error("Failed to record SCM polling"));
                        LOGGER
.log(Level.SEVERE,"Failed to record SCM polling",e);
                       
throw e;
                   
} finally {
                        listener
.close();
                   
}
               
} catch (IOException e) {
                    LOGGER
.log(Level.SEVERE,"Failed to record SCM polling",e);
               
}
               
return false;
           
}

           
public void run() {
               
if (runPolling()) {
                   
String name = " #"+job.getNextBuildNumber();
                   
BitBucketPushCause cause;
                   
try {
                        cause
= new BitBucketPushCause(getLogFile(), pushBy);
                   
} catch (IOException e) {
                        LOGGER
.log(Level.WARNING, "Failed to parse the polling log",e);
                        cause
= new BitBucketPushCause(pushBy);
                   
}
                   
ParameterizedJobMixIn pJob = new ParameterizedJobMixIn() {
                       
@Override protected Job asJob() {
                           
return job;
                       
}
                   
};
                   
BitBucketPayload bitBucketPayload = new BitBucketPayload(payload);
                    pJob
.scheduleBuild2(5, new CauseAction(cause), bitBucketPayload);
                   
if (pJob.scheduleBuild(cause)) {
                        LOGGER
.info("SCM changes detected in "+ job.getName()+". Triggering "+ name);
                   
} else {
                        LOGGER
.info("SCM changes detected in "+ job.getName()+". Job is already in the queue");
                   
}
               
}
           
}

       
});
   
}

The things my novice eyes notice in the function above is that it is a Runnable that is added to a getDescriptor().queue. Does this mean that only one of these can be processed at a time, or is it conceivable that two quick git pushes in succession can cause two of these runnables to execute at the same time.

The other thing I notice is that if pJob.scheduleBuild(cause) returns something that evaluates to false then we log a message that the job is already in the queue. Is a job in the queue when it is executing or does being in the queue mean that it is scheduled to be executed but hasn't startet yet?

Finally, I have a question about this statement from the function above:

   boolean result = SCMTriggerItem.SCMTriggerItems.asSCMTriggerItem(job).poll(listener).hasChanges();

hasChanges() relative to what? What happens if a job has been scheduled and it has started executing, but it has not decided yet what git sha or indeed even what git branch to build? Does that leave a window where a second git push triggers the job to be queued again?

I hope you can help me.

Thomas

Reply all
Reply to author
Forward
0 new messages