Custom checkout directory causes strange errors

Answered

TeamCity Professional 2019.2.3 (build 72031)

Setting custom checkout directory to %teamcity.build.default.checkoutDir% or to %system.teamcity.buildType.id% works fine, however setting it to %teamcity.build.default.checkoutDir%%system.teamcity.buildType.id% causes an out of memory error.

 

Updating sources: auto checkout (on agent) 3m:33s
0
15 comments

Are you using the same field for the custom and absolute path as in this screenshot? If not, where are you entering the custom path?

0

Yes I'm using this custom directory, and amazon latest version of Java as recommended. Java memory looks fine and is set to high numbers. Shorter resulting paths seem to work.

%teamcity.agent.home.dir%/../%system.teamcity.buildType.id%/%straykite.build.branch.clean%

 

0

> Setting custom checkout directory to %teamcity.build.default.checkoutDir% or to %system.teamcity.buildType.id% works fine, however setting it to %teamcity.build.default.checkoutDir%%system.teamcity.buildType.id% causes an out of memory error.

Can you provide an example of each parameter that work independently, but produces the error when used together? Or is it that you're using %teamcity.agent.home.dir%/../%system.teamcity.buildType.id%/%straykite.build.branch.clean% to cause the error? 

 

> Failed to perform checkout on agent: Problem while checkout on agent: java.lang.OutOfMemoryError: Java heap space

Since this problem appears to be occurring during checkout on the agent, what are your Java memory settings for the agent? You can look in the teamcity-agent.log file to verify the memory settings. It should be available in <build agent directory>/logs. You should find something like this when the agent starts up and should contain the JVM parameters for the agent. What is your Xmx setting?

===========================================================
TeamCity Build Agent 2019.2.1 (build 71758)
OS: Windows 10, version 10.0, x86, Current user: Build_Agent_1, Time zone: CDT (UTC-05:00)
Java: 1.8.0_222, OpenJDK Client VM (32 bit) (25.222-b10, mixed mode), OpenJDK Runtime Environment (1.8.0_222-b10), ; JVM parameters: -ea -Xmx512m -XX:+HeapDumpOnOutOfMemoryError -Xrs -Dlog4j.configuration=file:../conf/teamcity-agent-log4j.xml -Dteamcity_logs=../logs/
Starting...
Refreshing jetbrains.buildServer.agent.AgentMain2$3@8e6209: startup date [Wed Mar 11 11:39:59 CDT 2020]; root of context hierarchy
Calculating CPU benchmark index...
Agent tools download temp directory created on path C:\BuildAgent\temp\tools
Loading build agent configuration from C:\BuildAgent\conf\buildAgent.properties
Working dir: C:\BuildAgent\work
Temp dir: C:\BuildAgent\temp
===========================================================

 

> Error message is logged

You may also find some useful information on the out of memory error you're seeing in this logfile. Do you see the error in the teamcity-agent.log? If so, what do you see?

0

It doesn't seem to have anything to do with the parameters specifically but rather just the length of the path. If I hard-code the path, I get the same issue. There is an example in the error log below of one that does not work. If you split it up and use either half, it works.

 

Memory settings:

[2020-05-03 02:01:28,705] INFO - s.buildServer.agent.AgentMain2 - ===========================================================
[2020-05-03 02:01:28,721] INFO - s.buildServer.agent.AgentMain2 - TeamCity Build Agent 2019.2.3 (build 72031)
[2020-05-03 02:01:28,728] INFO - s.buildServer.agent.AgentMain2 - OS: Windows Server 2019, version 10.0, amd64, Current user: SKSSERVER01$, Time zone: CDT (UTC-05:00)
[2020-05-03 02:01:28,729] INFO - s.buildServer.agent.AgentMain2 - Java: 1.8.0_232, OpenJDK 64-Bit Server VM (25.232-b09, mixed mode), OpenJDK Runtime Environment (1.8.0_232-b09), Amazon.com Inc.; JVM parameters: -ea -Xmx512m -XX:+HeapDumpOnOutOfMemoryError -Xrs -Dlog4j.configuration=file:../conf/teamcity-agent-log4j.xml -Dteamcity_logs=../logs/
[2020-05-03 02:01:28,730] INFO - s.buildServer.agent.AgentMain2 - Starting...
[2020-05-03 02:01:28,768] INFO - buildServer.agent.AgentMain2$3 - Refreshing jetbrains.buildServer.agent.AgentMain2$3@79be0360: startup date [Sun May 03 02:01:28 CDT 2020]; root of context hierarchy
[2020-05-03 02:01:29,997] INFO - jetbrains.buildServer.AGENT - Calculating CPU benchmark index...
[2020-05-03 02:01:30,042] INFO - jetbrains.buildServer.AGENT - Agent tools download temp directory created on path D:\TeamCity\buildAgent\temp\tools
[2020-05-03 02:01:30,166] INFO - dAgentConfigurationInitializer - Loading build agent configuration from D:\TeamCity\buildAgent\conf\buildAgent.properties
[2020-05-03 02:01:30,279] INFO - s.buildServer.agent.AgentMain2 - Working dir: D:\TeamCity\buildAgent\work
[2020-05-03 02:01:30,279] INFO - s.buildServer.agent.AgentMain2 - Temp dir: D:\TeamCity\buildAgent\temp
[2020-05-03 02:01:30,291] INFO - rver.plugins.PluginManagerImpl - ===========================================================

 

Error from the build agent log file:

[2020-04-29 03:26:17,508]   INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateBuildTempDirectoryStage
[2020-04-29 03:26:17,509] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CleanBuildCheckoutDirectoryIfNeededStage
[2020-04-29 03:26:17,509] INFO - CheckoutDirectoryIfNeededStage - Will perform clean checkout. Reason: [ROOT_DIRECTORY_IS_EMPTY]
[2020-04-29 03:26:17,509] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateCheckoutDirectoryStage
[2020-04-29 03:26:17,509] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CleanGeneratedFilesStage
[2020-04-29 03:26:17,510] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.LogCheckoutDirectoryStage
[2020-04-29 03:26:17,510] INFO - jetbrains.buildServer.AGENT - Checkout directory: D:\TeamCity\buildAgent\work\db5cda79c6004db8Hydrogen_FullBuild
[2020-04-29 03:26:17,510] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.patch.CheckoutSourcesBuildStage
[2020-04-29 03:26:17,510] INFO - l.patch.AbstractSourcesUpdater - Updating sources: auto checkout (on agent)
[2020-04-29 03:26:17,510] INFO - jetbrains.buildServer.AGENT - Marking checkout directory db5cda79c6004db8Hydrogen_FullBuild for build id 706 as 'dirty'
[2020-04-29 03:26:17,512] INFO - jetbrains.buildServer.AGENT - No revision information for db5cda79c6004db8Hydrogen_FullBuild.xml on agent
[2020-04-29 03:26:17,512] INFO - jetbrains.buildServer.AGENT - Recording vcs state: revision: 55, VCS root signature: dc628397f9cab3e9, checkout rules: =>
-:UE4/Templates
-:UE4/Samples
-:UE4/FeaturePacks
-:UE4/Engine/Extras
-:UE4/Engine/Documentation
[2020-04-29 03:26:17,512] INFO - jetbrains.buildServer.AGENT - Stored new configuration file db5cda79c6004db8Hydrogen_FullBuild.xml
[2020-04-29 03:26:17,514] INFO - jetbrains.buildServer.AGENT - Marking checkout directory db5cda79c6004db8Hydrogen_FullBuild for build id 706 as 'clean'
[2020-04-29 03:26:17,514] INFO - pl.patch.ProjectSourcesOnAgent - Updating sources for root id=5; name=Plastic; checkout rules: =>; -:UE4/Templates; -:UE4/Samples; -:UE4/FeaturePacks; -:UE4/Engine/Extras; -:UE4/Engine/Documentation; revision: 55
[2020-04-29 03:26:18,910] INFO - ernalArtifactsProcessingLogger - Start: Publishing files using ArtifactsCachePublisher
[2020-04-29 03:26:18,913] INFO - ernalArtifactsProcessingLogger - Start: Publishing files using WebPublisher
[2020-04-29 03:26:18,915] INFO - ernalArtifactsProcessingLogger - Done publishing artifacts from [D:/TeamCity/buildAgent/temp/agentTmp/build.start.properties.gz] to [.teamcity/properties], using 'ArtifactsCachePublisher', total files published: 1
[2020-04-29 03:26:18,929] INFO - ernalArtifactsProcessingLogger - Done publishing artifacts from [D:/TeamCity/buildAgent/temp/agentTmp/build.start.properties.gz] to [.teamcity/properties], using 'WebPublisher', total files published: 1
[2020-04-29 03:26:18,929] INFO - ernalArtifactsProcessingLogger - Done: Publishing files
[2020-04-29 03:26:18,934] INFO - ernalArtifactsProcessingLogger - Publishing artifacts process finished
[2020-04-29 03:29:51,097] ERROR - pl.patch.ProjectSourcesOnAgent - Problem while checkout on agent
java.lang.OutOfMemoryError: Java heap space
[2020-04-29 03:29:51,098] WARN - l.patch.AbstractSourcesUpdater - Error while checkout on agent: Problem while checkout on agent: java.lang.OutOfMemoryError: Java heap space
jetbrains.buildServer.vcs.VcsException: Problem while checkout on agent: java.lang.OutOfMemoryError: Java heap space
at jetbrains.buildServer.agent.impl.patch.ProjectSourcesOnAgent$1.run(ProjectSourcesOnAgent.java:192)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.OutOfMemoryError: Java heap space
[2020-04-29 03:29:51,098] INFO - l.patch.AbstractSourcesUpdater - Sources update took 3m:33s

 

0

You say you get the same out of memory error if you use this as the Custom Path:

D:\TeamCity\buildAgent\work\db5cda79c6004db8Hydrogen_FullBuild

But earlier you said if you used this, it worked:

D:\%teamcity.build.default.checkoutDir%%system.teamcity.buildType.id%

Looking at your build log, it appears your %teamcity.build.default.checkoutDir% is D:\TeamCity\buildAgent\work\db5cda79c6004db8 and your %system.teamcity.buildType.id% is Hydrogen_FullBuild. The length of the path in your log file is not very long, I would be surprised if you're running into a limit here. I have seen much longer file paths used successfully. What is the resulting path when it works?

What other testing have you done that leads you to believe it is the custom path causing your out of memory error? As an experiment, could you try increasing the Agent jvm settings from -Xmx512m to -Xmx1g?

If you're running the Build Agent as a service, this setting is in the wrapper config file. See here for reference: https://www.jetbrains.com/help/teamcity/configuring-build-agent-startup-properties.html#ConfiguringBuildAgentStartupProperties-BuildAgentIsRunAsService

 

0

teamcity.build.default.checkoutDir is defined as the checkout directory as if no custom checkout directory had been specified, so in your example case, this should resolve to db5cda79c6004db8. Are you saying that parameter resolves to an absolute path and not just the directory name?

Shorter paths such as D:\checkout\Hydrogen_FullBuild work fine. This is my current work-around and all builds have been fine for the last two weeks. If I change it to make it longer again, it breaks with the out of memory error. If I turn off custom paths, it works fine. So while it might not be that setting by itself, that is the cause as far as I am concerned as an end user.

 

Increased to 1g and restored a longer path:

%teamcity.agent.home.dir%/tempcheckout/trysomethinglong/%system.teamcity.buildType.id%/%teamcity.build.branch%

Updating sources: auto checkout (on agent) 3m:31s
  Will use agent side checkout
VCS Root: Plastic 3m:28s
    revision: 248
java.lang.OutOfMemoryError: Java heap space   at java.util.Arrays.copyOfRange(Arrays.java:3664)   at java.lang.String.<init>(String.java:207)   at java.lang.StringBuilder.toString(StringBuilder.java:407)   at jetbrains.buildServer.agent.impl.patch.AbstractSourcesUpdater.suffix(AbstractSourcesUpdater.java:109)   at jetbrains.buildServer.agent.impl.patch.AbstractSourcesUpdater.logPatchExceptionInternal(AbstractSourcesUpdater.java:122)   at jetbrains.buildServer.agent.impl.patch.AbstractSourcesUpdater.logPatchProblem(AbstractSourcesUpdater.java:118)   at jetbrains.buildServer.agent.impl.patch.AbstractSourcesUpdater.doSourceUpdate(AbstractSourcesUpdater.java:83)   at jetbrains.buildServer.agent.impl.patch.CheckoutSourcesBuildStage$CheckoutAction.checkout(CheckoutSourcesBuildStage.java:115)   at jetbrains.buildServer.agent.impl.patch.CheckoutSourcesBuildStage$1.checkout(CheckoutSourcesBuildStage.java:65)   at jetbrains.buildServer.agent.impl.patch.CheckoutSourcesBuildStage.doCheckout(CheckoutSourcesBuildStage.java:81)   at jetbrains.buildServer.agent.impl.patch.CheckoutSourcesBuildStage.doRecoverableStage(CheckoutSourcesBuildStage.java:61)   at jetbrains.buildServer.agent.impl.buildStages.startStages.RecoverableBuildStage.doBuildStage(RecoverableBuildStage.java:75)   at jetbrains.buildServer.agent.impl.buildStages.BuildStagesExecutor$1.callStage(BuildStagesExecutor.java:31)   at jetbrains.buildServer.agent.impl.buildStages.BuildStagesExecutor$1.callStage(BuildStagesExecutor.java:24)   at jetbrains.buildServer.agent.impl.buildStages.StagesExecutor.callRunStage(StagesExecutor.java:76)   at jetbrains.buildServer.agent.impl.buildStages.StagesExecutor.doStages(StagesExecutor.java:35)   at jetbrains.buildServer.agent.impl.buildStages.BuildStagesExecutor.doStages(BuildStagesExecutor.java:24)   at jetbrains.buildServer.agent.impl.BuildRunActionImpl.doStages(BuildRunActionImpl.java:79)   at jetbrains.buildServer.agent.impl.BuildRunActionImpl.runBuild(BuildRunActionImpl.java:55)   at jetbrains.buildServer.agent.impl.BuildAgentImpl.doActualBuild(BuildAgentImpl.java:312)   at jetbrains.buildServer.agent.impl.BuildAgentImpl.access$100(BuildAgentImpl.java:55)   at jetbrains.buildServer.agent.impl.BuildAgentImpl$1.run(BuildAgentImpl.java:275)   at java.lang.Thread.run(Thread.java:748)
Unexpected error: java.lang.OutOfMemoryError: Java heap space

 

Reset path to:

%teamcity.agent.home.dir%/../%system.teamcity.buildType.id%/%straykite.build.branch.clean%

with no other changes, build successful.

Updating sources: auto checkout (on agent) 2m:55s
  Will use agent side checkout
VCS Root: Plastic 2m:55s
    revision: 248
Step 1/9: Build build tool (Command Line) 5s
  Starting: D:\TeamCity\Hydrogen_FullBuild\main\Build\SKSBuild\build.bat

 

 

 

Current wrapper memory settings on the agent I tested on below. I don't think most of these are necessary changes, I was just trying everything to make this error go away. Would love to know what's needed / unnecessary.

# TeamCity agent launcher parameters
# Preventing launcher exit on x64 when user logs off
wrapper.java.additional.1=-Xrs
# sks:shovaen -begin-
# https://www.jetbrains.com/help/teamcity/configuring-build-agent-startup-properties.html
# https://www.jetbrains.com/help/teamcity/installing-and-configuring-the-teamcity-server.html
wrapper.java.additional.2=-Xmx4g
wrapper.java.additional.3=-XX:ReservedCodeCacheSize=450m
wrapper.java.additional.4=-XX:+UseG1GC
# sks:shovaen -end-

# Initial Java Heap Size (in MB)
wrapper.java.initmemory=1024 # sks:shovaen increased

# Maximum Java Heap Size (in MB)
wrapper.java.maxmemory=4096 # sks:shovaen increased

###########################################################
### TeamCity agent JVM parameters
###
### NOTE: There should be no gaps in parameters numbers, if
### NOTE: you change parameters, you need to update numbering
###
##########################################################
# Application parameters.
wrapper.app.parameter.1=jetbrains.buildServer.agent.StandAloneLauncher
wrapper.app.parameter.2=-ea
wrapper.app.parameter.3=-Xmx1g
# The next line can be removed (and the rest of the parameter names MUST BE renumbered) to prevent memory dumps on OutOfMemoryErrors
wrapper.app.parameter.4=-XX:+HeapDumpOnOutOfMemoryError
# Preventing process exiting on user log off
wrapper.app.parameter.5=-Xrs
# Uncomment the next line (insert the number instead of "N" and renumber the rest of the lines) to improve JVM performance
wrapper.app.parameter.6=-server

 

0

Sorry, you are correct on the parameter values. I'll chalk that one up to it being Monday. Regarding the wrapper.conf file, there are two sections, one for the launcher and one for the agent JVM. The most important setting is the -Xmx memory, which is the maximum memory allocation for the JVM. How much memory is available on the agent server? It looks like it is probably running on the TeamCity Server, is this right? If that is the case, can you screenshot the Administration | Diagnostics | Memory Usage chart? It would be especially helpful while the build is running.

These settings are for the launcher and are not normally needed to be changed at all. I'd recommend changing these back to the defaults (see my settings further below):

# TeamCity agent launcher parameters
# Preventing launcher exit on x64 when user logs off
wrapper.java.additional.1=-Xrs
# sks:shovaen -begin-
# https://www.jetbrains.com/help/teamcity/configuring-build-agent-startup-properties.html
# https://www.jetbrains.com/help/teamcity/installing-and-configuring-the-teamcity-server.html
wrapper.java.additional.2=-Xmx4g
wrapper.java.additional.3=-XX:ReservedCodeCacheSize=450m
wrapper.java.additional.4=-XX:+UseG1GC
# sks:shovaen -end-

# Initial Java Heap Size (in MB)
wrapper.java.initmemory=1024 # sks:shovaen increased

# Maximum Java Heap Size (in MB)
wrapper.java.maxmemory=4096 # sks:shovaen increased

These are the agent JVM settings and would be much more likely to have an impact on your build:

# Application parameters.
wrapper.app.parameter.1=jetbrains.buildServer.agent.StandAloneLauncher
wrapper.app.parameter.2=-ea
wrapper.app.parameter.3=-Xmx1g
# The next line can be removed (and the rest of the parameter names MUST BE renumbered) to prevent memory dumps on OutOfMemoryErrors
wrapper.app.parameter.4=-XX:+HeapDumpOnOutOfMemoryError
# Preventing process exiting on user log off
wrapper.app.parameter.5=-Xrs
# Uncomment the next line (insert the number instead of "N" and renumber the rest of the lines) to improve JVM performance
wrapper.app.parameter.6=-server

Here are the settings from my wrapper.conf, which are about the most basic settings you can use if you find it helpful:

#********************************************************************
# Java Service Wrapper Properties for TeamCity Agent Launcher
#********************************************************************

#####################################################################
###
### The path should point to 'java' program.
###
#####################################################################

wrapper.java.command=../../jre/bin/java

wrapper.java.mainclass=org.tanukisoftware.wrapper.WrapperSimpleApp

# Java Classpath
wrapper.java.classpath.1=../launcher/lib/wrapper.jar
wrapper.java.classpath.2=../launcher/lib/launcher.jar

# Java Library Path (location of Wrapper.DLL or libwrapper.so)
wrapper.java.library.path.1=../launcher/lib
wrapper.java.library.path.2=../launcher/bin

# TeamCity agent launcher parameters
#Preventing launcher exit on x64 when user logs off
wrapper.java.additional.1=-Xrs

# Initial Java Heap Size (in MB)
wrapper.java.initmemory=16

# Maximum Java Heap Size (in MB)
wrapper.java.maxmemory=64

###########################################################
### TeamCity agent JVM parameters
###
### NOTE: There should be no gaps in parameters numbers, if
### NOTE: you change parameters, you need to update numbering
###
##########################################################
# Application parameters.
wrapper.app.parameter.1=jetbrains.buildServer.agent.StandAloneLauncher
wrapper.app.parameter.2=-ea
wrapper.app.parameter.3=-Xmx512m
# The next line can be removed (and the rest of the parameter names MUST BE renumbered) to prevent memory dumps on OutOfMemoryErrors
wrapper.app.parameter.4=-XX:+HeapDumpOnOutOfMemoryError
# Preventing process exiting on user log off
wrapper.app.parameter.5=-Xrs
# Uncomment the next line (insert the number instead of "N" and renumber the rest of the lines) to improve JVM performance
#wrapper.app.parameter.N=-server
wrapper.app.parameter.6=-Dlog4j.configuration=file:../conf/teamcity-agent-log4j.xml
wrapper.app.parameter.7=-Dteamcity_logs=../logs/
wrapper.app.parameter.8=jetbrains.buildServer.agent.AgentMain
# TeamCity agent parameters
wrapper.app.parameter.9=-file
wrapper.app.parameter.10=../conf/buildAgent.properties

 

0

Okay I've changed everything to match your warpper.conf except for -Xmx1g and -server (assuming this is meant to be set if the agent is on the server? if not I'll remove this as well).

We do have two other agents that are not on the server which both exhibit the same issue. The server has 128GB of RAM (most of which is unused, currently at 38/128 with no build running), the other agents have 64GB.

Prior to build starting:

 

During build:

After build failed to start:

 

0

Thanks for the additional information on your environment and the charts. I am not sure you need to use the -server option, but it is unlikely to affect your issue either way. My understanding of the -server option is that it will allow for faster throughput at the cost of longer startup times.

One more quick experiment would be to try setting your Xmx to an extreme value like 4gb? 

wrapper.app.parameter.3=-Xmx4g

 If you still get the out of memory error at that point, we can look at your memory dump from the error for anything useful. There should be one created with each error in the <build agent home>/bin directory. Look for a file like: java_pidxxxx.hprof. You can upload it to me on our FTP, instructions are here: https://www.jetbrains.com/help/teamcity/reporting-issues.html#ReportingIssues-UploadingLargeDataArchives. Just be sure to let me know the exact filename so I can find it.

0

Increased to 4g and got:

 

  VCS Root: Plastic 10s
0

Thanks so much, this is very helpful. It looks like you have uncovered something I will need to discuss with our developers. I just have a couple of follow-up questions. Which type of VCS are you using for this build configuration? Has this same build configuration worked in earlier releases of TeamCity?

0

No problem.

Plastic SCM is the VCS.

This has not worked for us previously, but we just started with TeamCity about a month ago.

Should I keep the memory setting at 4g?

0

The limitation you're seeing is a component of the Plastic SCM plugin. While it looks like a workaround would be to use a shorter checkout directory, as you had already discovered, I would suggest reaching out to the vendor of the plugin to let them know of the issue so they can have the opportunity to patch it. If you're using the Plastic SCM from our plugin repository, it looks to be directly from the makers of Plastic SCM and they have support on their website here: https://www.plasticscm.com/documentation/technical-articles/how-to-integrate-plastic-scm-with-teamcity-ci.

The memory setting of 4gb would be a bit higher than average, however, it did resolve your out of memory error. Since it appears that you have plenty of memory available on the server, you won't hurt anything by leaving it there. 

0

Okay, thanks Eric. Were you able to reproduce the issue?

I have a support thread going with them on this issue as well. Didn't know where the problem was so figured it was best to look at it from both ends.

0

No problem, it was an interesting issue to look at and I think we got your java settings on your build agent straightened out if nothing else. I was not able to reproduce your issue on my end, but I do not have any Plastic SCM VCS roots to experiment on. 

0

Please sign in to leave a comment.