[JIRA] (JENKINS-38741) Job DSL execution is occassionally slow on large scale production servers

2 views
Skip to first unread message

thefriendlycoder@gmail.com (JIRA)

unread,
Oct 5, 2016, 10:52:02 AM10/5/16
to jenkinsc...@googlegroups.com
Kevin Phillips created an issue
 
Jenkins / Bug JENKINS-38741
Job DSL execution is occassionally slow on large scale production servers
Issue Type: Bug Bug
Assignee: Daniel Spilker
Components: job-dsl-plugin
Created: 2016/Oct/05 2:51 PM
Priority: Minor Minor
Reporter: Kevin Phillips

We have several Jenkins jobs which do nothing more than execute a single build step for running job DSL code. Further, some of these scripts are responsible for dynamically generating hundreds of new jobs. Now, sometimes these scripts run through to completion quickly (ie: 60 seconds or less) but other times they take severely long periods of time to complete (ie: 20-30 minutes or more).

Based on some crude investigations on my part trolling through build logs and poking around at the source code for the job DSL plugin, what I think it happening is that after the job DSL gets processed a list of newly generated and / or modified job configs are stored in memory and then the Jenkins master is 'scheduled' to run each of the individual job operations whenever it can. In these extreme situations it appears to take a very long period of time for all of these individual job operations (for which there are hundreds) to get scheduled and run. For example, when looking at the time stamps of specific log messages on the master we see it may be as much as 60 seconds from when one job update operation completes and the next one begins, with other unrelated output from the master in between.

Why this happens exactly, I am not sure. The conditions causing the slowdown are difficult at best to reproduce. I can say that in our production environment the Jenkins master runs on a virtual machine with considerable resources assigned to it, and we don't have any executors configured on the master so any load it may see is 100% associated with the master processes and not some unpredictable build operation.

If anyone can shed some light on why this behaves as it does, and whether there's anything we can do on our end to try and mitigate the issue that would be awesome. Otherwise, it would be nice to see some sort of implementation change in the plugin itself to try and ensure the performance from the generation process is kept consistent between runs.

Add Comment Add Comment
 
This message was sent by Atlassian JIRA (v7.1.7#71011-sha1:2526d7c)
Atlassian logo

thefriendlycoder@gmail.com (JIRA)

unread,
Oct 5, 2016, 10:55:01 AM10/5/16
to jenkinsc...@googlegroups.com
Kevin Phillips updated an issue
Change By: Kevin Phillips
Environment: Jenkins 1.642.4
Job DSL plugin v1.42

thefriendlycoder@gmail.com (JIRA)

unread,
Oct 5, 2016, 11:00:03 AM10/5/16
to jenkinsc...@googlegroups.com
Kevin Phillips commented on Bug JENKINS-38741
 
Re: Job DSL execution is occassionally slow on large scale production servers

I'm not sure if this may be relevant or not, but I have noticed that some of the jobs generated by our scripts are being detected as 'changed' even when there hasn't been any changes to their respective DSL code. As an associated side effect, I've noticed that immediately after running our DSL scripts, if you examine some of the jobs that get generated they have some notification text on them indicating that their job configuration has been changed since they were created ... even though there have been no manual modifications made to them.

I'm guessing that somewhere in our DSL scripts, the XML that is being generated is somehow slightly different than what the Jenkins service is expecting and it performs some sort of pre-processing logic to the XML when it gets stored to disk thus causing a discrepancy between what is running in production and what is generated by the scripts.

I suspect that maybe one reason the DSL generation is slow on occassion is partially caused by extra overhead on the Jenkins master to perform these pre-processing operations and if there were some way for us to avoid these false-positives it may minimize the overhead on the master and may avoid whatever bottleneck we are hitting.

thefriendlycoder@gmail.com (JIRA)

unread,
Oct 5, 2016, 11:01:02 AM10/5/16
to jenkinsc...@googlegroups.com
Kevin Phillips updated an issue
Change By: Kevin Phillips
We have several Jenkins jobs which do nothing more than execute a single build step for running job DSL code. Further, some of these scripts are responsible for dynamically generating hundreds of new jobs. Now, sometimes these scripts run through to completion quickly (ie: 60 seconds or less) but other times they take severely long periods of time to complete (ie: 20-30 minutes or more).

Based on some crude investigations on my part trolling through build logs and poking around at the source code for the job DSL plugin, what I think it happening is that after the job DSL gets processed a list of newly generated and / or modified job configs are stored in memory and then the Jenkins master is 'scheduled' to run each of the individual job operations whenever it can. In these extreme situations it appears to take a very long period of time for all of these individual job operations (for which there are hundreds) to get scheduled and run. For example, when looking at the time stamps of specific log messages on the master we see it may be as much as 60 seconds from when one job update operation completes and the next one begins, with other unrelated output from the master in between.

Why this happens exactly, I am not sure. The conditions causing the slowdown are difficult at best to reproduce. I can say that in our production environment the Jenkins master runs on a virtual machine with considerable resources assigned to it, and we don't have any executors configured on the master so any load it may see is 100% associated with the master processes and not some unpredictable build operation.

If anyone can shed some light on why this behaves as it does, and whether there's anything we can do on our end to try and mitigate the issue that would be awesome. Otherwise Also , it would be nice to see some sort of implementation change in the plugin itself to try and ensure the performance from the generation process is kept consistent between runs.

thefriendlycoder@gmail.com (JIRA)

unread,
Oct 5, 2016, 11:01:02 AM10/5/16
to jenkinsc...@googlegroups.com
Kevin Phillips updated an issue
We have several Jenkins jobs which do nothing more than execute a single build step for running job DSL code. Further, some of these scripts are responsible for dynamically generating hundreds of new jobs. Now, sometimes these scripts run through to completion quickly (ie: 60 seconds or less) but other times they take severely long periods of time to complete (ie: 20-30 minutes or more).

Based on some crude investigations on my part trolling through build logs and poking around at the source code for the job DSL plugin, what I think it happening is that after the job DSL gets processed a list of newly generated and / or modified job configs are stored in memory and then the Jenkins master is 'scheduled' to run each of the individual job operations whenever it can. In these extreme situations it appears to take a very long period of time for all of these individual job operations (for which there are hundreds) to get scheduled and run. For example, when looking at the time stamps of specific log messages on the master we see it may be as much as 60 seconds from when one job update operation completes and the next one begins, with other unrelated output from the master in between.

Why this happens exactly, I am not sure. The conditions causing the slowdown are difficult at best to reproduce. I can say that in our production environment the Jenkins master runs on a virtual machine with considerable resources assigned to it, and we don't have any executors configured on the master so any load it may see is 100% associated with the master processes and not some unpredictable build operation.

If anyone can shed some light on why this behaves as it does, and whether there's anything we can do on our end to try and mitigate the issue that would be awesome. Also, it would be nice to see some sort of implementation change in the plugin itself to try and ensure the performance from the generation process is kept consistent between runs . (ie: if all job configuration updates could be scheduled as a single larger operation instead of many smaller ones)

chris.and.amy.shannon@gmail.com (JIRA)

unread,
Oct 5, 2016, 2:12:01 PM10/5/16
to jenkinsc...@googlegroups.com
Christopher Shannon commented on Bug JENKINS-38741
 
Re: Job DSL execution is occassionally slow on large scale production servers

I can confirm that running a job DSL script causes a significant load on the master. Our Jenkins instance was previously running on my laptop, and my PC would become almost unusable while a job DSL script was running.

We have since moved to a real server and increased the max heap size that Jenkins can consume considerably, so it is no longer an issue for us.

I'd be curious from the output of this thread "what" it is doing, but can at least confirm that there is a very noticeable load put on the master while a script is being processed.

vladichko@gmail.com (JIRA)

unread,
Oct 9, 2016, 4:20:01 PM10/9/16
to jenkinsc...@googlegroups.com

mail@daniel-spilker.com (JIRA)

unread,
Oct 12, 2016, 5:27:01 AM10/12/16
to jenkinsc...@googlegroups.com

The "Process Job DSLs" build steps always runs on the master, even if the job is assigned to an executor on an agent (aka slave). The Job DSL build steps needs to modify the internal memory structures in Jenkins, so running the step on an agent would require a lot of remote communication which would make the step every slow and cause load on both, master and agent. When running on an agent, the seed job's workspace will reside on the agent machine. Since the script runs on the master it needs to load all scripts and files through the remote channel, which does not make things faster. So in general it is discouraged to run the seed job on an agent.

There are several reasons why the performance may be slow sometimes. One is memory pressure and garbage collection. There are several tools to monitor a Java process, e.g. could try the Monitoring Plugin. If your Jenkins master is short of memory and/or doing a lot of GC, your system will be slow. You need to find out if that's the case.

Another reason why the seed job may be slow is that lot of lock contention is happening in Jenkins master. The Job DSL build steps modifies internal structure in Jenkins (job config, view config, etc). To ensure that the internal data is consistent, Jenkins uses locks to prevent multiple threads from modifying data concurrently. If your Jenkins instance is under load, e.g. many job are running, then a lot of internal data structures are modified. So it may happen that a thread (e.g. the executor running the seed job) must wait to acquire a lock to modify data. And so your seed job may take time until all locks are acquired and all data is modified. There are a lot of profiling tools to analyze lock contention. A simple method to debug lock contention is using thread dumps. If your seed job is slow, take a few thread dumps from Jenkins master in short intervals (e.g. 5 seconds) and then analyze the thread dumps for any threads that are blocked.

thefriendlycoder@gmail.com (JIRA)

unread,
Oct 12, 2016, 9:31:07 AM10/12/16
to jenkinsc...@googlegroups.com

Lock contention does seem like a plausible explanation for this behavior. I'm not an avid Java developer so I'll need to figure out how to do thread dumps and setup the tools necessary to analyze the thread usage to see if I can confirm. If you have any tips / links that could help me along please let me know.

chris.and.amy.shannon@gmail.com (JIRA)

unread,
Oct 12, 2016, 3:59:01 PM10/12/16
to jenkinsc...@googlegroups.com

Waiting for locks could certainly explain variability in the latency of a Job DSL run, which I suppose is the crux of this original issue, but would not explain the high load that we see on the master node while the job is running...

mail@daniel-spilker.com (JIRA)

unread,
Oct 13, 2016, 7:47:02 AM10/13/16
to jenkinsc...@googlegroups.com

chris.and.amy.shannon@gmail.com (JIRA)

unread,
Oct 13, 2016, 8:16:01 AM10/13/16
to jenkinsc...@googlegroups.com

I suppose that this is possible. I have looked at the output of the monitoring plugin and the spikes in CPU utilization don't necessarily correlate to drops in memory utilization, which I'd expect from a garbage collection...

mail@daniel-spilker.com (JIRA)

unread,
Oct 17, 2016, 9:48:05 AM10/17/16
to jenkinsc...@googlegroups.com

You can use this script to create a few thread dumps from Jenkins master: http://wiki.eclipse.org/How_to_report_a_deadlock#jstackSeries_--_jstack_sampling_in_fixed_time_intervals_.28tested_on_Linux.29

Run the script when the load is high on master, zip the generated files and attach the archive to this issue.

martin.nonnenmacher@gmail.com (JIRA)

unread,
Nov 9, 2016, 4:33:01 AM11/9/16
to jenkinsc...@googlegroups.com

Kevin Phillips: Jenkins does indeed modify the XML generated by Job DSL. For example it adds plugin attributes referencing the plugin version to some tags. As a result many more jobs are updated than required. This especially leads to performance problems when the Job Config History plugin is used without configuring a retention, because the plugin reads the full history of a job when it is updated, and history can become very large when the seed job runs often. I think the XML comparison done by Job DSL could be improved, but I did not spend much time on the investigation.

martin.nonnenmacher@gmail.com (JIRA)

unread,
Nov 9, 2016, 4:34:01 AM11/9/16
to jenkinsc...@googlegroups.com
Martin Nonnenmacher edited a comment on Bug JENKINS-38741
[~leedega]: Jenkins does indeed modify the XML generated by Job DSL. For example it adds plugin attributes referencing the plugin version to some tags. As a result many more jobs are updated than required. This especially leads to performance problems when the Job Config History plugin is used without configuring a retention, because the plugin reads the full history of a job when it is updated, and the history can become very large when the seed job runs often. I think the XML comparison done by Job DSL could be improved, but I did not spend much time on the investigation.

chris.and.amy.shannon@gmail.com (JIRA)

unread,
Nov 9, 2016, 7:32:06 AM11/9/16
to jenkinsc...@googlegroups.com

Martin Nonnenmacher: Super informative comment. I can confirm on our side that we do have the Job Config History plugin, many jobs, and likely many jobs without a retention policy in place. That probably goes a long way to explaining the server load we're seeing on our end.

The that isn't clear, though, what do you mean by "many more jobs are updated than required"? Is Jenkins updating jobs that aren't generated by that particular run of the Job DSL? Or is it just the job history of those generated jobs that increases the load?

martin.nonnenmacher@gmail.com (JIRA)

unread,
Nov 9, 2016, 11:06:03 AM11/9/16
to jenkinsc...@googlegroups.com

I meant that because Jenkins is changing the XML Job DSL thinks the job has changed and is updating it, instead of skipping. This creates a new entry in the job config history for affected jobs every time the seed job runs. For example one of or seed jobs is always updating about 90% of the jobs, even when only one of them was changed. Some of our jobs had hundreds of entries in the config history after a while and suddenly the updates became extremely slow. By configuring a retention for the config history we could increase the runtime of the seed job by factor 100.

Please also be aware that the retention for the config history needs to be configured globally in the system settings, not per job. Currently we only run into locking issues sometimes when a folder on the root level is updated (1-2 minutes delay), but job updates are very fast.

mail@daniel-spilker.com (JIRA)

unread,
Feb 20, 2017, 11:39:02 AM2/20/17
to jenkinsc...@googlegroups.com

I'm going to close this as not reproducible if there is no proof that something in Job DSL can be fixed for this issue.

mail@daniel-spilker.com (JIRA)

unread,
Aug 26, 2019, 7:13:03 AM8/26/19
to jenkinsc...@googlegroups.com

Is there still a problem when using newer versions of Jenkins and Job DSL? If not, I'm going to close this ticket.

This message was sent by Atlassian Jira (v7.11.2#711002-sha1:fdc329d)
Reply all
Reply to author
Forward
0 new messages