StackOverflow2013

Note that there are some explanatory texts on larger screens.

plurals

POWhy does a hudson "mvn clean install" build take 3-6x longer than the same on the command line?
text
Body
copied!<p>We are seeing relatively long build times on our CI server (hudson) and they're starting to get in our way. I am aware hudson does more than invoke maven and I would happily grant it 10-20% more time for the job, but an order of magnitude slowdown seems too much.</p> <p>Anyone have an idea of why this might be and how to solve the problem? I will start by saying what is <em>not</em> the cause:</p> <ul> <li>the virtual machine hudson is running in: on the command line, it takes roughly the same amount of time as my development PC</li> <li>other concurrent tasks: I made sure there was nothing diverting resources from the build task</li> </ul> <p>The maven goals are literally clean and install, nothing fancy and resource-intensive like javadoc, checkstyle etc. Looking at the hudson build task console output, there seem to be delays when "Retrieving previous build number from [our Nexus artefact repository]", but I don't know of a simple way to measure performance of this step and publishing an artefact seems too simple an operation to justify the total difference in speed.</p> <p>(problem also described in <a href="http://hudson.361315.n4.nabble.com/Hudson-Maven2-slow-execution-td3015735.html" rel="nofollow">this</a> thread)</p> <p><strong>Update:</strong></p> <p>We have upgraded Hudson/Jenkins to the latest release and have been able to use the timing plugin. Short version:</p> <ul> <li>the good news: we now know <strong>nexus is causing the problem</strong></li> <li>the bad news: we still don't know why</li> </ul> <p>More details</p> <p>On one of our actual maven projects (maven build time: 3 min, hudson build time: 9 min) we could see that hudson also performs the build in 3 min, but then takes 6 minutes to upload the artefact to nexus.</p> <p>Performing a manual upload of another artefact using nexus' web UI, I was able to confirm the following:</p> <ul> <li>the actual artefact upload is done in a fraction of the time (i.e., in several seconds)</li> <li>after these several seconds, the artefact appears as <code><nexusworkdir>/nexus/storage/test/test2/test2/1.0.0/test2-1.0.0.rpm</code></li> </ul> <p><strong>The real puzzler</strong> is why nexus takes over a minute to create this file: <code><nexusworkdir>/nexus/proxy/attributes/test/test2/test2/1.0.0/test2-1.0.0.rpm</code></p> <p>As far as I can tell, it just calculates an MD5 and SHA1 signature and records general artefact information, but md5sum and sha1sum of a 75MB file take <1s to run...</p> <p>Finally, it does not appear to be some sort of network time-out, because the delay seems to be roughly proportional to artefact size.</p> <p>Any idea what nexus does after it receives an artefact is appreciated.</p> <p><strong>Update 2</strong>:</p> <p>Setting the nexus log level to debug, nexus logs the following when an artefact is uploaded:</p> <blockquote> <pre><code>... 2011-04-05 14:38:53 DEBUG [jpsc28za2RtYQ==] - </code></pre> <p>o.s.n.p.s.l.f.Defau~ - Copying stream with buffer size of: 4096</p> <pre><code>2011-04-05 14:39:55 DEBUG [ython-2.5.2.jar] - org.mortbay.log </code></pre> <p>- RESPONSE /nexus/content/groups/public/org/python/jython/2.5.2/jython-2.5.2.jar 200</p> <pre><code>2011-04-05 14:40:07 DEBUG [-2.5.2.jar.sha1] - org.mortbay.log </code></pre> <p>- REQUEST /nexus/content/groups/public/org/python/jython/2.5.2/jython-2.5.2.jar.sha1 on</p> <pre><code>... 2011-04-05 14:40:12 DEBUG [-2.5.2.jar.sha1] - org.mortbay.log </code></pre> <p>- RESPONSE /nexus/content/groups/public/org/python/jython/2.5.2/jython-2.5.2.jar.sha1 200</p> <pre><code>2011-04-05 14:43:45 DEBUG [ndex.properties] - org.mortbay.log </code></pre> <p>- REQUEST /nexus/content/groups/public/.index/nexus-maven-repository-index.properties on org.mortbay.jetty.HttpConnection@141a720</p> <pre><code>... 2011-04-05 14:44:04 DEBUG [ndex.properties] - </code></pre> <p>o.s.n.p.m.m.M2Group~ - public retrieveItem() :: FOUND public:/.index/nexus-maven-repository-index.properties</p> <pre><code>2011-04-05 14:44:04 DEBUG [ndex.properties] - org.mortbay.log </code></pre> <p>- RESPONSE /nexus/content/groups/public/.index/nexus-maven-repository-index.properties 200</p> <pre><code>2011-04-05 14:48:07 DEBUG [jpsc28za2RtYQ==] - </code></pre> <p>o.s.n.p.a.DefaultAt~ - Storing attributes on UID=test:/test/test/1.0.1/test-1.0.1.rpm</p> <pre><code>... 2011-04-05 14:48:07 DEBUG [w/icon-info.gif] - org.mortbay.log </code></pre> <p>- servlet holder=nexus</p> <pre><code>2011-04-05 14:48:08 DEBUG [w/icon-info.gif] - org.mortbay.log </code></pre> <p>- RESPONSE /nexus/ext-2.3/resources/images/default/window/icon-info.gif 200</p> <pre><code>2011-04-05 14:49:01 DEBUG [c=1302007326656] - org.mortbay.log </code></pre> <p>- REQUEST /nexus/service/local/log/config on org.mortbay.jetty.HttpConnection@1dbd88f ....</p> </blockquote> <p>It appears to just be sitting there for a minute or so and than continues with its work. Any idea why nexus does this is appreciated.</p>

Querying!

Guidance

An individual column

Larger individual text columns get their own page to allow for proper reading.

SQuiL has stopped working due to an internal error.

If you are curious you may find further information in the browser console, which is accessible through the devtools (F12).

Reload