Sloooooooooooooow SVN checkouts

Most of my build configurations contain two SVN roots:

The first SVN root points to a SVN module that is our IVY repository where we house all our third-party libraries and all of our internally generated artifacts. The second SVN root points to a SVN module that contains the project being built.

When a build is initiated, it will sit for minutes just checking out the IVY repository and then the same for the project. For example, if i execute the ant target from within the IDE, it runs in 24 seconds; however executing the same ant target under TC takes over 2 minutes--this is for only 40 tests. I have another project with a little over 700 tests that runs in a couple of minutes under the IDE but takes ~20 minutes under TC.

BTW, it has been this way since the 1.2 release ...

19 comments
Comment actions Permalink

Jeff,

Please check that you build configurations are not configured to clean sources before each build ("Clean all files before build" is off on General settings). Clean sources checkout also occurs if it is the first time build is run on the given agent, if VCS settings were changed or if the sources update process failed for some reason.

If you suspect the builds perform clean sources checkout while they should not, please gather agent and server logs and send them to us so that we can investigate the issue in more detail.

You can check how much time each step takes from the build log timestamps.
What are the sources checkout/update steps times for the builds mentioned?

Do you have Externals support enabled for the VCS roots? You can turn it off if you do not use externals.

What checkout mode do you use (agent or server)? Did you customize build working directory for the builds?

While builds run by TeamCity can run a bit slower then in console (providing there is some overhead on sending messages to the server), the difference should be pretty much neglectable.

--
Best regards,

Yegor Yarko
Quality Assurance Engineer
JetBrains, Inc
http://www.jetbrains.com
"Develop with pleasure!"

0
Comment actions Permalink

I see it too and it makes it impractical for us to use on the third-party library root. It seems like TC does a complete fresh checkout if there is any change in a root. It is fast if there is no change in the root but full checkout slow if there is even just 1 change in the root.

Can we set TC to just do an svn update? Why doesn't it take this approach by default? We really need a more incremental approach. Even better, if the server watches the repository, it can just update the changed files for maximum performance, right?

Here is sample timing on a root:
A) Full checkout: 8 minutes
B) Full update: 1-2 minutes
C) Only update individual files: a few seconds
Am I right that TC is doing A if there is any change? Shouldn't TC do C if it has the information or else fall back to B?

Thanks,
Jon

0
Comment actions Permalink

i have the "clean all files" option disabled; however from what i've observed the state of this option doesn't seem to make a difference.

a few minutes ago, i just disabled the externals support for all my projects and like above it doesn't seem to make a difference.

i use the "check out on agent" option for my builds and i do not customize the working directory. i do however set the VCS checkout subdirectory for each of the roots. here is the typical project structure:


my teamcity-vcs.log file is empty, but i do have a ton of these in the teamcity-agent.log file:


INFO - r.agent.impl.AgentLogProxyImpl - jetbrains.buildServer.xmlrpc.RemoteCallException: Call http://dfwdevas2:8080/
TeamCity-2.0/RPC2 buildServer.log: org.apache.xmlrpc.XmlRpcClientException: Error decoding XML-RPC response
jetbrains.buildServer.xmlrpc.RemoteCallException: Call http://dfwdevas2:8080/TeamCity-2.0/RPC2 buildServer.log: org.apache.xmlrpc.XmlRpcClientExc
eption: Error decoding XML-RPC response
at
jetbrains.buildServer.xmlrpc.AbstractXmlRpcTarget.call(AbstractXmlRpcTarget.java:60)
at jetbrains.buildServer.agent.impl.XmlRpcAgentLogListener.log(XmlRpcAgentLogListener.java:38)
at jetbrains.buildServer.agent.impl.AgentLogProxyImpl.sendLog(AgentLogProxyImpl.java:148)
at jetbrains.buildServer.agent.impl.AgentLogProxyImpl.access$500(AgentLogProxyImpl.java:22)
at jetbrains.buildServer.agent.impl.AgentLogProxyImpl$5.run(AgentLogProxyImpl.java:178)
at jetbrains.buildServer.agent.impl.AgentLogProxyImpl.sendActionRequest(AgentLogProxyImpl.java:69)
at jetbrains.buildServer.agent.impl.AgentLogProxyImpl.access$100(AgentLogProxyImpl.java:22)
at jetbrains.buildServer.agent.impl.AgentLogProxyImpl$2.run(AgentLogProxyImpl.java:97)
at jetbrains.buildServer.agent.impl.AgentLogProxyImpl$LaterExecutorTask.doRun(AgentLogProxyImpl.java:246)
at jetbrains.buildServer.agent.impl.AgentLogProxyImpl$LaterExecutorTask.run(AgentLogProxyImpl.java:227)
at java.util.TimerThread.mainLoop(Timer.java:512)
at java.util.TimerThread.run(Timer.java:462)
Caused by: org.apache.xmlrpc.XmlRpcClientException: Error decoding XML-RPC response
at org.apache.xmlrpc.XmlRpcClientResponseProcessor.decodeResponse(XmlRpcClientResponseProcessor.java:80)
at org.apache.xmlrpc.XmlRpcClientWorker.execute(XmlRpcClientWorker.java:73)
at org.apache.xmlrpc.TCXmlRpcClient$1.execute(TCXmlRpcClient.java:65)
at org.apache.xmlrpc.XmlRpcClient.execute(XmlRpcClient.java:194)
at org.apache.xmlrpc.XmlRpcClient.execute(XmlRpcClient.java:185)
at org.apache.xmlrpc.XmlRpcClient.execute(XmlRpcClient.java:178)
at jetbrains.buildServer.xmlrpc.AbstractXmlRpcTarget.call(AbstractXmlRpcTarget.java:54)
... 11 more
Caused by: org.xml.sax.SAXParseException: Premature end of file.
at com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.parse(AbstractSAXParser.java:1269)
at org.apache.xmlrpc.XmlRpc.parse(XmlRpc.java:472)
at org.apache.xmlrpc.XmlRpcClientResponseProcessor.decodeResponse(XmlRpcClientResponseProcessor.java:68)
... 17 more

0
Comment actions Permalink

Hmm, when you use VCS checkout mode of "Automatically on server", does it always send the entire root to the Agent if there is any change? What scenarios would you use "Automatically on server" and what other ones for "Automatically on agent"?

Thanks,
Jon

0
Comment actions Permalink

Hello Jeff,

first of all, you can disable svn externals for the root if you don't use
them, it has to speed svn connection up.

If getting project sources is still slow or you suspect agent gets all
sources instead of changed files only, please provide us logs from server
and the agent.
Thanks!

--
Olesya Smirnova
JetBrains, Inc
http://www.jetbrains.com
"Develop with pleasure!"


"Jeff Glatz" <no_reply@jetbrains.com> wrote in message
news:22182911.1186681331111.JavaMail.itn@is.intellij.net...

Most of my build configurations contain two SVN roots:

>

The first SVN root points to a SVN module that is our IVY repository where
we house all our third-party libraries and all of our internally generated
artifacts. The second SVN root points to a SVN module that contains the
project being built.

>

When a build is initiated, it will sit for minutes just checking
out the IVY repository and then the same for the project. For example, if
i execute the ant target from within the IDE, it runs in 24 seconds;
however executing the same ant target under TC takes over 2 minutes--this
is for only 40 tests. I have another project with a little over 700 tests
that runs in a couple of minutes under the IDE but takes ~20 minutes under
TC.

>

BTW, it has been this way since the 1.2 release ...



0
Comment actions Permalink

Hmm, when you use VCS checkout mode of "Automatically on server", does it
always send the entire root to the Agent if there is any change?


It doesn't. If checkout mode is "on agent" update command is being called,
for "server" mode server builds "patch" with changed files and agent applyes
it to existing files.

But if agent cannot report to server what version of sources is applied, or
there is error during the patch process, working directory will be cleaned
and all files will be requested from the server.

--
Olesya Smirnova
JetBrains, Inc
http://www.jetbrains.com
"Develop with pleasure!"


"Jon Steelman" <no_reply@jetbrains.com> wrote in message
news:15652691.1186686344762.JavaMail.itn@is.intellij.net...

Hmm, when you use VCS checkout mode of "Automatically on server", does it
always send the entire root to the Agent if there is any change? What
scenarios would you use "Automatically on server" and what other ones for
"Automatically on agent"?

>

Thanks,
Jon



0
Comment actions Permalink

The esception shows agent cannot log some message from build to server and
cannot be a cause of clean checkout.
But, there might be similar exception about agent attempt of sending to
server last updated version. It leads to full check out on every build.
Could you please attach or send directly to me all server and agent logs?

Thanks!

--
Olesya Smirnova
JetBrains, Inc
http://www.jetbrains.com
"Develop with pleasure!"


"Jeff Glatz" <no_reply@jetbrains.com> wrote in message
news:28034183.1186686900674.JavaMail.itn@is.intellij.net...
>i have the "clean all files" option disabled; however from
>what i've observed the state of this option doesn't seem to make a
>difference.
>

a few minutes ago, i just disabled the externals support for
all my projects and like above it doesn't seem to make a difference.

>

i use the "check out on agent" option for my builds and i *do
not* customize the working directory. i do however set the *VCS
checkout subdirectory* for each of the roots. here is the typical
project structure:

>

 /u01/app/ci/BuildAgent/work/Agent
>    Ingrian_Connector
>        libraries                (IVY repository root)
>        ingrian                  (project root)
> ]]>

>

my teamcity-vcs.log file is empty, but i do have a ton of these in
the teamcity-agent.log file:

>
>

INFO - r.agent.impl.AgentLogProxyImpl -
jetbrains.buildServer.xmlrpc.RemoteCallException: Call
http://dfwdevas2:8080/
TeamCity-2.0/RPC2 buildServer.log:
org.apache.xmlrpc.XmlRpcClientException: Error decoding XML-RPC response
jetbrains.buildServer.xmlrpc.RemoteCallException: Call
http://dfwdevas2:8080/TeamCity-2.0/RPC2 buildServer.log:
org.apache.xmlrpc.XmlRpcClientExc
eption: Error decoding XML-RPC response
at
jetbrains.buildServer.xmlrpc.AbstractXmlRpcTarget.call(AbstractXmlRpcTarget.java:60)
at
jetbrains.buildServer.agent.impl.XmlRpcAgentLogListener.log(XmlRpcAgentLogListener.java:38)
at
jetbrains.buildServer.agent.impl.AgentLogProxyImpl.sendLog(AgentLogProxyImpl.java:148)
at
jetbrains.buildServer.agent.impl.AgentLogProxyImpl.access$500(AgentLogProxyImpl.java:22)
at
jetbrains.buildServer.agent.impl.AgentLogProxyImpl$5.run(AgentLogProxyImpl.java:178)
at
jetbrains.buildServer.agent.impl.AgentLogProxyImpl.sendActionRequest(AgentLogProxyImpl.java:69)
at
jetbrains.buildServer.agent.impl.AgentLogProxyImpl.access$100(AgentLogProxyImpl.java:22)
at
jetbrains.buildServer.agent.impl.AgentLogProxyImpl$2.run(AgentLogProxyImpl.java:97)
at
jetbrains.buildServer.agent.impl.AgentLogProxyImpl$LaterExecutorTask.doRun(AgentLogProxyImpl.java:246)
at
jetbrains.buildServer.agent.impl.AgentLogProxyImpl$LaterExecutorTask.run(AgentLogProxyImpl.java:227)
at java.util.TimerThread.mainLoop(Timer.java:512)
at java.util.TimerThread.run(Timer.java:462)
Caused by: org.apache.xmlrpc.XmlRpcClientException: Error decoding XML-RPC
response
at
org.apache.xmlrpc.XmlRpcClientResponseProcessor.decodeResponse(XmlRpcClientResponseProcessor.java:80)
at
org.apache.xmlrpc.XmlRpcClientWorker.execute(XmlRpcClientWorker.java:73)
at
org.apache.xmlrpc.TCXmlRpcClient$1.execute(TCXmlRpcClient.java:65)
at org.apache.xmlrpc.XmlRpcClient.execute(XmlRpcClient.java:194)
at org.apache.xmlrpc.XmlRpcClient.execute(XmlRpcClient.java:185)
at org.apache.xmlrpc.XmlRpcClient.execute(XmlRpcClient.java:178)
at
jetbrains.buildServer.xmlrpc.AbstractXmlRpcTarget.call(AbstractXmlRpcTarget.java:54)
... 11 more
Caused by: org.xml.sax.SAXParseException: Premature end of file.
at
com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.parse(AbstractSAXParser.java:1269)
at org.apache.xmlrpc.XmlRpc.parse(XmlRpc.java:472)
at
org.apache.xmlrpc.XmlRpcClientResponseProcessor.decodeResponse(XmlRpcClientResponseProcessor.java:68)
... 17 more



0
Comment actions Permalink

Jon,

Both server-side and agent-side checkout perform sources update, not full checkout (only the changes since the revision stored on agent are retrieved from the version control).
If you experience unnecessary full checkouts, that's subject to further investigation.

Agent-side checkout is supported only for some VCSs (Subversion and CVS at this time).
It also moves part of load from the server to agents and provides ability to access version control-specific directories (.svn, CVS) i.e. build script can perform check-ins into the version control.

However, there are some configurations (e.g. necessity to setup SSL certificates) where server-side checkout is easier to configure.

--
Best regards,

Yegor Yarko
Quality Assurance Engineer
JetBrains, Inc
http://www.jetbrains.com
"Develop with pleasure!"

0
Comment actions Permalink

Jeff,

Your configuration should work fine. We have alike setup and no full sources checkout.

The exceptions in the log can be related, but we will need full logs (at least for one build) from both agent and server to investigate exceptions' origin.

--
Best regards,

Yegor Yarko
Quality Assurance Engineer
JetBrains, Inc
http://www.jetbrains.com
"Develop with pleasure!"

0
Comment actions Permalink

Agent-side checkout is supported only for some VCSs
(Subversion and CVS at this time).
It also moves part of load from the server to agents
and provides ability to access version
control-specific directories (.svn, CVS) i.e. build
script can perform check-ins into the version
control.

However, there are some configurations (e.g.
necessity to setup SSL certificates) where
server-side checkout is easier to configure.


Hi Yegor & Olesya,

Assuming that you have a supported Agent VCS and you can get everything configured, wouldn't you go Agent? I guess I can see that the load on the VCS server would be less with the Server model, but other than that, is Agent the better way to go over Server? Which would and do you use and why?

Thanks!
Jon

0
Comment actions Permalink

Jon,

Agent-side checkout seems to be more preferable, but there is no much difference other then already noted.

Internally, we use both, but it's more for historical reasons then for any others.

--
Best regards,

Yegor Yarko
Quality Assurance Engineer
JetBrains, Inc
http://www.jetbrains.com
"Develop with pleasure!"

0
Comment actions Permalink

Jon,

Generally, TeamCity does B. It is real "update" for the agent-side checkout and "find all files that were changed in repository since agent-stored revision and overwrite them with latest repository revisions" for server-side checkout.

If you experience other behavior, please create an issue to investigate the problem.

--
Best regards,

Yegor Yarko
Quality Assurance Engineer
JetBrains, Inc
http://www.jetbrains.com
"Develop with pleasure!"

0
Comment actions Permalink

I thought I'd add to this thread because I'm experiencing an extreme form of this. I have 2 projects setup similarly:
VCS Checkout Mode: automatic on server (agent is on same machine)
Build options: clean all files is NOT checked
SVN Connection tests fine
use externals option is disabled

Project A is a single Maven module and checks out, builds fine.
Project B is multi-module Maven build. When I run the build for Project B it gets to "Getting sources..." in the log and then it just sits there. I got tired of waiting after about 30 minutes and stopped it manually, then last night I let it run when I left the office and when I came in this morning this is what was in my buildAgent/logs/teamcity-agent.log:
INFO - jetbrains.buildServer.AGENT - Getting sources...
INFO - jetbrains.buildServer.AGENT - Requesting patch from server, cleanPatch
=true
INFO - jetbrains.buildServer.AGENT - Copying patch to temp file...
WARN - jetbrains.buildServer.AGENT - Failed to apply patch.
java.io.IOException: No space left on device
at java.io.FileOutputStream.writeBytes(Native Method)
at java.io.FileOutputStream.write(FileOutputStream.java:260)
at java.io.BufferedOutputStream.write(BufferedOutputStream.java:105)
at jetbrains.buildServer.util.TCStreamUtil.writeBinary(TCStreamUtil.java:78)
at jetbrains.buildServer.agent.impl.BuildAgentImpl.copyPatchToTempFile(BuildAgentImpl.java:889)
at jetbrains.buildServer.agent.impl.BuildAgentImpl.applyPatch(BuildAgentImpl.java:780)
at jetbrains.buildServer.agent.impl.BuildAgentImpl.getProjectSources(BuildAgentImpl.java:578)
at jetbrains.buildServer.agent.impl.BuildAgentImpl.access$1300(BuildAgentImpl.java:50)
at jetbrains.buildServer.agent.impl.BuildAgentImpl$6.run(BuildAgentImpl.java:482)
at java.lang.Thread.run(Thread.java:595)
INFO - jetbrains.buildServer.AGENT - Sources loaded for 21245 seconds

Notice that there was a gap of 5 HOURS between "requesting patch from server" and "copying patch to temp file" before complaining about being out of space. There was still space on the drive but regardless I cleaned up a ton today and tried again with no change. I also tried setting checkout mode as "automatically on agent" but still no luck. I've turned the logging level to DEBUG for all of the appenders but didn't see anything in the logs that jumped out at me.

Any ideas?

0
Comment actions Permalink

An update: I changed checkout mode to "automatic on agent" and ran again, this time it took 1.5 hours to check everything out.

Any special logging tips to help me track this down?

0
Comment actions Permalink

Please send to me or attach here all teamcity-performance.log* files.

Do you have "clean checkout" option enabled for the configuration?

BTW, how big is the project? If there are a lot of files changed they are getting from svn server to TC server, then sending to the agent. On the TC server and agent patch file (with contents of all changed files) is being saved to the temp file (otherwise there are problems with timeout and tomcat sends broken stream content). So a very big file will be saved several times, it takes some time, checking out on the agent reduces such savings.

0
Comment actions Permalink

Sorry, I gorgot to mention, you have to uncomment section
]]>
if the log4j configuration file conf/teamcity-server-log4j.xml and restart the server to obtain performance logs.

0
Comment actions Permalink

I see the output below in my "build log" in our TeamCity website but can't seem to find it anywhere in an actual log file (must be missing something obvious). I consistently get this message when this project builds (now about 1.5 hours to check out sources) even though other projects work out fine. This project is definitely bigger, perhaps 50MB total to checkout. The message says 'No space left on device' which presumably means no space left on the TeamCity server host, although all mounts that I can find on that box are comfortably under 50% capacity, with the temp mounts under 20%. I ran this last build with performance logging enabled and it understandably spit out a lot of stuff, shall I post that here too as a separate message? I don't see any way to attach or upload a file so not sure if there is a better alternative. Anyway here's the output from the "Important Messages" when viewing the failed build:

jetbrains.buildServer.vcs.VcsException: org.tmatesoft.svn.core.SVNException: svn: REPORT request failed on '/prod/fmmCds/!svn/vcc/default'
svn: No space left on device
jetbrains.buildServer.vcs.VcsException: org.tmatesoft.svn.core.SVNException: svn: REPORT request failed on '/prod/fmmCds/!svn/vcc/default'
svn: No space left on device
at jetbrains.buildServer.vcs.svn.SvnCheckoutOnAgentSupport.updateSources(SvnCheckoutOnAgentSupport.java:33)
at jetbrains.buildServer.agent.impl.BuildAgentImpl.checkoutSources(BuildAgentImpl.java:632)
at jetbrains.buildServer.agent.impl.BuildAgentImpl.getProjectSources(BuildAgentImpl.java:582)
at jetbrains.buildServer.agent.impl.BuildAgentImpl.access$1300(BuildAgentImpl.java:50)
at jetbrains.buildServer.agent.impl.BuildAgentImpl$6.run(BuildAgentImpl.java:482)
at java.lang.Thread.run(Thread.java:595)
Caused by: org.tmatesoft.svn.core.SVNException: svn: REPORT request failed on '/prod/fmmCds/!svn/vcc/default'
svn: No space left on device
at org.tmatesoft.svn.core.internal.wc.SVNErrorManager.error(SVNErrorManager.java:80)
at org.tmatesoft.svn.core.internal.io.dav.http.HTTPConnection.request(HTTPConnection.java:519)
at org.tmatesoft.svn.core.internal.io.dav.http.HTTPConnection.request(HTTPConnection.java:236)
at org.tmatesoft.svn.core.internal.io.dav.http.HTTPConnection.request(HTTPConnection.java:224)
at org.tmatesoft.svn.core.internal.io.dav.DAVConnection.doReport(DAVConnection.java:219)
at org.tmatesoft.svn.core.internal.io.dav.DAVConnection.doReport(DAVConnection.java:211)
at org.tmatesoft.svn.core.internal.io.dav.DAVRepository.update(DAVRepository.java:617)
at org.tmatesoft.svn.core.wc.SVNUpdateClient.doUpdate(SVNUpdateClient.java:162)
at org.tmatesoft.svn.core.wc.SVNUpdateClient.doCheckout(SVNUpdateClient.java:344)
at jetbrains.buildServer.vcs.svn.TCSvnUpdateClient.doCheckout(TCSvnUpdateClient.java:49)
at jetbrains.buildServer.vcs.svn.SvnCheckoutOnAgentSupport.updateSources(SvnCheckoutOnAgentSupport.java:26)
... 5 more


Cheers,
John

0
Comment actions Permalink

John,

performance logs don't contian profiling information for agent side checkout, please switch mode to server-side and run build after this.
You can upload logs there: ftp://ftp.intellij.net/.uploads
50MB project shouldn't takes 5h to be checked out, I think, the problem is not in its size. BTW, do you use externals in the project? Try to disable "use externals" options for vcs root if not, it might reduce checkout time.

0
Comment actions Permalink

It is with sheepish humility that I must report that the problem turned out to be an incorrect SVN URL. I had set the project to checkout from svnrepo/myproj instead of svnrepo/myproj/trunk, which means effectively every time I requested a build TeamCity was trying to checkout the current trunk, branch, and all 30+ tags!! Corrected the URL, TeamCity now works like a charm. Many thanks to a fantastic support team for trying to work though my mistakes though

0

Please sign in to leave a comment.