Failing builds due to "Exception occurred while patch applying: Failed to create directory"
Using the most current Teamcity version (TeamCity 8.1.2, build 29993) we have several build agents which produce quite a number of failed builds with the exception "Exception occurred while patch applying: Failed to create directory". These exceptions seem to occur randomly, so the same project may build one time but fail the next time but the issue seems to increase with the time the agent is running and seems to be gone for the first few builds after the agent has been restarted. The directory which cannot be created doesn't exist and there is no problem creating it manually so this shouldn't be an issue with a different process keeping a handle to a file or something (nevertheless we have disabled any antivirus software etc. but the problem still persists). Any ideas on what we can try to fix this?
The agent log provides the following output:
[2014-05-28 06:36:15,983] INFO - jetbrains.buildServer.AGENT - ===================================================
[2014-05-28 06:36:15,983] INFO - jetbrains.buildServer.AGENT - Starting build buildId = 71231, buildTypeId=bt121
[2014-05-28 06:36:15,984] INFO - mpl$TeamCitySpringSubConatiner - Refreshing SubContext: running build context id=71231: startup date [Wed May 28 06:36:15 CEST 2014]; parent: jetbrains.buildServer.agent.AgentMain2$2@150b2d
[2014-05-28 06:36:16,099] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.LogAgentParametersStage
[2014-05-28 06:36:16,100] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.ClearExpiredBuildWorkingDirectoriesStage
[2014-05-28 06:36:16,100] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.UpdateDirectoryMapStage
[2014-05-28 06:36:16,117] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.RegisterPropertiesFileNamesStage
[2014-05-28 06:36:16,122] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.EnableBuildStopStage
[2014-05-28 06:36:16,122] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.FireBuildStartedStage
[2014-05-28 06:36:16,131] INFO - uildServer.swabra.SwabraLogger - Swabra cleanup is disabled
[2014-05-28 06:36:16,131] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CleanAgentTempDirectoryStage
[2014-05-28 06:36:16,147] INFO - rectories.DirectoryCleanerImpl - Move directory C:\BuildAgent\temp\agentTmp to C:\BuildAgent\temp\.old\agentTmp_0 for cleaning
[2014-05-28 06:36:16,147] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateAgentTempDirectoryStage
[2014-05-28 06:36:16,148] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.PublishBuildPropertiesStage
[2014-05-28 06:36:16,164] INFO - ernalArtifactsProcessingLogger - Publishing artifacts process started
[2014-05-28 06:36:16,164] INFO - ernalArtifactsProcessingLogger - Start: Searching for artifacts to publish in [C:\BuildAgent\temp\agentTmp\build.start.properties.gz=>.teamcity/properties]
[2014-05-28 06:36:16,164] INFO - ernalArtifactsProcessingLogger - Done: Searching for artifacts to publish, found [1] file
[2014-05-28 06:36:16,164] INFO - ernalArtifactsProcessingLogger - Start: Pre-processing artifacts if needed (archiving)
[2014-05-28 06:36:16,164] INFO - ernalArtifactsProcessingLogger - Done: Pre-processing artifacts if needed (archiving)
[2014-05-28 06:36:16,164] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CleanBuildTempDirectoryStage
[2014-05-28 06:36:16,164] INFO - s.CleanBuildTempDirectoryStage - Clearing temporary directory: C:\BuildAgent\temp\buildTmp
[2014-05-28 06:36:16,179] INFO - rectories.DirectoryCleanerImpl - Move directory C:\BuildAgent\temp\buildTmp to C:\BuildAgent\temp\.old\buildTmp_0 for cleaning
[2014-05-28 06:36:16,180] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateBuildTempDirectoryStage
[2014-05-28 06:36:16,180] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateCheckoutDirectoryStage
[2014-05-28 06:36:16,182] INFO - ace.DirectoryCleanerForceClean - Free disk space under directory C:\BuildAgent\system is 46.51 GB, required 3 GB.
[2014-05-28 06:36:16,182] INFO - ace.DirectoryCleanerForceClean - Free disk space under directory D:\BuildAgent\work\developDaily_Test_NUnit_UI is 251.43 GB, required 3 GB.
[2014-05-28 06:36:16,182] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CleanGeneratedFilesStage
[2014-05-28 06:36:16,182] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.LogCheckoutDirectoryStage
[2014-05-28 06:36:16,182] INFO - jetbrains.buildServer.AGENT - Checkout directory: D:\BuildAgent\work\developDaily_Test_NUnit_UI
[2014-05-28 06:36:16,182] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.patch.UpdateSourcesFromServer
[2014-05-28 06:36:16,182] INFO - ch.UpdateSourcesBuildStageBase - Updating sources: server side checkout
[2014-05-28 06:36:16,183] INFO - .patch.UpdateSourcesFromServer - Requesting patch from server, full checkout - true
[2014-05-28 06:36:16,183] INFO - .patch.UpdateSourcesFromServer - Downloading patch to temp file...
[2014-05-28 06:36:16,183] INFO - jetbrains.buildServer.AGENT - No revision information for developDaily_Test_NUnit_UI.xml on agent
[2014-05-28 06:36:16,187] INFO - ernalArtifactsProcessingLogger - Start: Publishing files using ArtifactsCachePublisher
[2014-05-28 06:36:16,189] INFO - ernalArtifactsProcessingLogger - Start: Publishing files using WebPublisher
[2014-05-28 06:36:16,194] INFO - ernalArtifactsProcessingLogger - Done publishing artifacts to '.teamcity/properties', using 'ArtifactsCachePublisher', total files published: 1
[2014-05-28 06:36:16,227] INFO - ernalArtifactsProcessingLogger - Done publishing artifacts to '.teamcity/properties', using 'WebPublisher', total files published: 1
[2014-05-28 06:36:16,227] INFO - ernalArtifactsProcessingLogger - Done: Publishing files
[2014-05-28 06:36:16,232] INFO - ernalArtifactsProcessingLogger - Publishing artifacts process finished
[2014-05-28 06:41:15,760] INFO - gent.impl.patch.PatchTempFiles - Patch downloaded
[2014-05-28 06:41:15,760] INFO - impl.patch.PatchDownloaderImpl - Checking the patch is correct...
[2014-05-28 06:41:15,882] INFO - impl.patch.PatchDownloaderImpl - Patch checking finished
[2014-05-28 06:41:15,882] INFO - jetbrains.buildServer.AGENT - Patch downloaded for build with id 71231
[2014-05-28 06:41:15,917] INFO - jetbrains.buildServer.AGENT - Attempting to mark checkoutdir developDaily_Test_NUnit_UI for build 71231 dirty
[2014-05-28 06:41:15,917] INFO - jetbrains.buildServer.AGENT - Number of vcsRootEntries: [VcsRootEntry[VcsSettings["ReleaseAsset" {internal id=13, properties: [externals-mode=externals-none; labelingMessage=Labeled automatically by TeamCity; labelingPatterns=trunk=>tags; secure:svn-password=*****; svn-config-directory=C:\Windows\system32\config\systemprofile\AppData\Roaming\Subversion; svn-use-default-config-directory=true; teamcity:vcsRootName=ReleaseAsset; url=*****; user=*****; vcs=*****; working-copy-format=1.7; ]}; Checkout rules: -:.
+:1_Sources/ReleaseAsset/Test/Data
+:1_Sources/ReleaseAsset/Test/Tools]]]
[2014-05-28 06:41:15,917] INFO - jetbrains.buildServer.AGENT - Recording vcs state. C: 1471_2014/05/23 11:21:50 +0200, Id: 13, CR: 1_Sources/ReleaseAsset/Test/Tools=>1_Sources/ReleaseAsset/Test/Tools
1_Sources/ReleaseAsset/Test/Data=>1_Sources/ReleaseAsset/Test/Data
-:.
[2014-05-28 06:41:15,917] INFO - jetbrains.buildServer.AGENT - Moved configuration file developDaily_Test_NUnit_UI.xml to old
[2014-05-28 06:41:15,918] INFO - jetbrains.buildServer.AGENT - Stored new configuration file developDaily_Test_NUnit_UI.xml
[2014-05-28 06:41:15,918] INFO - .patch.UpdateSourcesFromServer - Applying patch to checkout directory...
[2014-05-28 06:41:16,738] WARN - ch.UpdateSourcesBuildStageBase - Exception occurred while patch applying: Failed to create directory: D:\BuildAgent\work\developDaily_Test_NUnit_UI
jetbrains.buildServer.vcs.patches.PatchException: Failed to create directory: D:\BuildAgent\work\developDaily_Test_NUnit_UI
at jetbrains.buildServer.vcs.patches.StrictPatcherErrorHandler.error(StrictPatcherErrorHandler.java:24)
at jetbrains.buildServer.vcs.patches.PatcherErrorHandlerBase.error(PatcherErrorHandlerBase.java:63)
at jetbrains.buildServer.vcs.patches.PatcherErrorHandlerBase.addDirectoryFailed(PatcherErrorHandlerBase.java:19)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.addDirectory(FSPatcherCallbackImpl.java:48)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.ensureParentFolder(FSPatcherCallbackImpl.java:145)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.addDirectory(FSPatcherCallbackImpl.java:30)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.ensureParentFolder(FSPatcherCallbackImpl.java:145)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.addDirectory(FSPatcherCallbackImpl.java:30)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.ensureParentFolder(FSPatcherCallbackImpl.java:145)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.addDirectory(FSPatcherCallbackImpl.java:30)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.ensureParentFolder(FSPatcherCallbackImpl.java:145)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.addDirectory(FSPatcherCallbackImpl.java:30)
at jetbrains.buildServer.vcs.patches.AbstractFSPatcher$Bridge.addDirectory(AbstractFSPatcher.java:78)
at jetbrains.buildServer.vcs.patches.AbstractPatcher$1.addDirectory(AbstractPatcher.java:60)
at jetbrains.buildServer.vcs.patches.AbstractPatcher$1.addDirectory(AbstractPatcher.java:42)
at jetbrains.buildServer.vcs.patches.LowLevelPatcher.readPatchStream(LowLevelPatcher.java:103)
at jetbrains.buildServer.vcs.patches.LowLevelPatcher.applyPatch(LowLevelPatcher.java:88)
at jetbrains.buildServer.vcs.patches.AbstractPatcher.applyPatch(AbstractPatcher.java:42)
at jetbrains.buildServer.vcs.patches.AbstractFSPatcher.applyPatch(AbstractFSPatcher.java:33)
at jetbrains.buildServer.agent.impl.patch.PatchApplierImpl.applyPatch(PatchApplierImpl.java:18)
at jetbrains.buildServer.agent.impl.patch.UpdateSourcesPatcherBase.applyPatch(UpdateSourcesPatcherBase.java:75)
at jetbrains.buildServer.agent.impl.patch.UpdateSourcesFromServer.applyPatchToDisc(UpdateSourcesFromServer.java:79)
at jetbrains.buildServer.agent.impl.patch.UpdateSourcesFromServer.updateSources(UpdateSourcesFromServer.java:65)
at jetbrains.buildServer.agent.impl.patch.UpdateSourcesBuildStageBase.doSourceUpdate(UpdateSourcesBuildStageBase.java:91)
at jetbrains.buildServer.agent.impl.patch.UpdateSourcesBuildStageBase.doRecoverableStage(UpdateSourcesBuildStageBase.java:59)
at jetbrains.buildServer.agent.impl.buildStages.startStages.RecoverableBuildStage.doBuildStage(RecoverableBuildStage.java:74)
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:78)
at jetbrains.buildServer.agent.impl.buildStages.StagesExecutor.doStages(StagesExecutor.java:37)
at jetbrains.buildServer.agent.impl.buildStages.BuildStagesExecutor.doStages(BuildStagesExecutor.java:24)
at jetbrains.buildServer.agent.impl.BuildRunAction.doStages(BuildRunAction.java:70)
at jetbrains.buildServer.agent.impl.BuildRunAction.runBuild(BuildRunAction.java:50)
at jetbrains.buildServer.agent.impl.BuildAgentImpl.doActualBuild(BuildAgentImpl.java:265)
at jetbrains.buildServer.agent.impl.BuildAgentImpl.access$100(BuildAgentImpl.java:52)
at jetbrains.buildServer.agent.impl.BuildAgentImpl$1.run(BuildAgentImpl.java:231)
at java.lang.Thread.run(Unknown Source)
Please sign in to leave a comment.
Does it produce the same error on all agents (that have this problem)? Is the agent's D: drive is a regular drive (not a mapped/memory/etc. one)? Does it happen for all build configuration or just a few ones?
Also, can you please attach more log examples?
The error is the same on all agents. The drive D: is jus ta regular partition on the same physical drive as the primary partition (C:) with Windows. The issue seems to happen for all projects regardless of VCS root etc..
Here are two more examples from a different agent (Drive E: si also a regular drive here) and a different projects:
Example 1:
2014-05-28 07:37:03,265] INFO - jetbrains.buildServer.AGENT - ===================================================
[2014-05-28 07:37:03,265] INFO - jetbrains.buildServer.AGENT - Starting build buildId = 71238, buildTypeId=bt13
[2014-05-28 07:37:03,266] INFO - mpl$TeamCitySpringSubConatiner - Refreshing SubContext: running build context id=71238: startup date [Wed May 28 07:37:03 CEST 2014]; parent: jetbrains.buildServer.agent.AgentMain2$2@1271218
[2014-05-28 07:37:03,402] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.LogAgentParametersStage
[2014-05-28 07:37:03,402] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.ClearExpiredBuildWorkingDirectoriesStage
[2014-05-28 07:37:03,402] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.UpdateDirectoryMapStage
[2014-05-28 07:37:03,424] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.RegisterPropertiesFileNamesStage
[2014-05-28 07:37:03,435] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.EnableBuildStopStage
[2014-05-28 07:37:03,435] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.FireBuildStartedStage
[2014-05-28 07:37:03,441] INFO - uildServer.swabra.SwabraLogger - Swabra cleanup is disabled
[2014-05-28 07:37:03,441] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CleanAgentTempDirectoryStage
[2014-05-28 07:37:03,492] INFO - rectories.DirectoryCleanerImpl - Move directory E:\BuildAgent\temp\agentTmp to E:\BuildAgent\temp\.old\agentTmp_8 for cleaning
[2014-05-28 07:37:03,492] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateAgentTempDirectoryStage
[2014-05-28 07:37:03,493] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.PublishBuildPropertiesStage
[2014-05-28 07:37:03,501] INFO - ernalArtifactsProcessingLogger - Publishing artifacts process started
[2014-05-28 07:37:03,501] INFO - ernalArtifactsProcessingLogger - Start: Searching for artifacts to publish in [E:\BuildAgent\temp\agentTmp\build.start.properties.gz=>.teamcity/properties]
[2014-05-28 07:37:03,501] INFO - ernalArtifactsProcessingLogger - Done: Searching for artifacts to publish, found [1] file
[2014-05-28 07:37:03,501] INFO - ernalArtifactsProcessingLogger - Start: Pre-processing artifacts if needed (archiving)
[2014-05-28 07:37:03,501] INFO - ernalArtifactsProcessingLogger - Done: Pre-processing artifacts if needed (archiving)
[2014-05-28 07:37:03,501] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CleanBuildTempDirectoryStage
[2014-05-28 07:37:03,501] INFO - s.CleanBuildTempDirectoryStage - Clearing temporary directory: E:\BuildAgent\temp\buildTmp
[2014-05-28 07:37:03,547] INFO - rectories.DirectoryCleanerImpl - Move directory E:\BuildAgent\temp\buildTmp to E:\BuildAgent\temp\.old\buildTmp_8 for cleaning
[2014-05-28 07:37:03,547] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateBuildTempDirectoryStage
[2014-05-28 07:37:03,548] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.DirtySourcesIfCleanBuildStage
[2014-05-28 07:37:03,548] INFO - jetbrains.buildServer.AGENT - Patch downloaded for build with id 71238
[2014-05-28 07:37:03,551] INFO - ernalArtifactsProcessingLogger - Start: Publishing files using ArtifactsCachePublisher
[2014-05-28 07:37:03,553] INFO - ernalArtifactsProcessingLogger - Start: Publishing files using WebPublisher
[2014-05-28 07:37:03,564] INFO - ernalArtifactsProcessingLogger - Done publishing artifacts to '.teamcity/properties', using 'ArtifactsCachePublisher', total files published: 1
[2014-05-28 07:37:03,581] INFO - ernalArtifactsProcessingLogger - Done publishing artifacts to '.teamcity/properties', using 'WebPublisher', total files published: 1
[2014-05-28 07:37:03,581] INFO - ernalArtifactsProcessingLogger - Done: Publishing files
[2014-05-28 07:37:03,585] INFO - ernalArtifactsProcessingLogger - Publishing artifacts process finished
[2014-05-28 07:37:03,616] INFO - jetbrains.buildServer.AGENT - Attempting to mark checkoutdir projectPlan for build 71238 dirty
[2014-05-28 07:37:03,616] INFO - jetbrains.buildServer.AGENT - Number of vcsRootEntries: [VcsRootEntry[VcsSettings["Project Plan" {internal id=14, properties: [externals-mode=externals-none; labelingMessage=Labeled automatically by TeamCity; labelingPatterns=trunk=>tags; secure:svn-password=*****; svn-config-directory=C:\Windows\system32\config\systemprofile\AppData\Roaming\Subversion; svn-use-default-config-directory=true; teamcity:vcsRootName=Project Plan; url=*****; user=*****; vcs=svn; working-copy-format=1.7; ]}; Checkout rules: ]]]
[2014-05-28 07:37:03,619] INFO - jetbrains.buildServer.AGENT - Recording vcs state. C: 3673, Id: 14, CR: =>
[2014-05-28 07:37:03,620] INFO - jetbrains.buildServer.AGENT - Moved configuration file projectPlan.xml to old
[2014-05-28 07:37:03,621] INFO - jetbrains.buildServer.AGENT - Stored new configuration file projectPlan.xml
[2014-05-28 07:37:03,622] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CleanBuildCheckoutDirectoryIfNeededStage
[2014-05-28 07:37:03,623] INFO - CheckoutDirectoryIfNeededStage - Clean build enabled: removing old files from E:\BuildAgent\work\projectPlan
[2014-05-28 07:37:03,677] INFO - rectories.DirectoryCleanerImpl - Move directory E:\BuildAgent\work\projectPlan to E:\BuildAgent\work\.old\projectPlan_8 for cleaning
[2014-05-28 07:37:03,677] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateCheckoutDirectoryStage
[2014-05-28 07:37:03,680] INFO - ace.DirectoryCleanerForceClean - Free disk space under directory E:\BuildAgent\system is 87.76 GB, required 3 GB.
[2014-05-28 07:37:03,680] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CleanGeneratedFilesStage
[2014-05-28 07:37:03,681] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.LogCheckoutDirectoryStage
[2014-05-28 07:37:03,681] INFO - jetbrains.buildServer.AGENT - Checkout directory: E:\BuildAgent\work\projectPlan
[2014-05-28 07:37:03,681] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.patch.UpdateSourcesFromServer
[2014-05-28 07:37:03,681] INFO - ch.UpdateSourcesBuildStageBase - Updating sources: server side checkout
[2014-05-28 07:37:03,681] INFO - .patch.UpdateSourcesFromServer - Requesting patch from server, full checkout - true
[2014-05-28 07:37:03,681] INFO - .patch.UpdateSourcesFromServer - Downloading patch to temp file...
[2014-05-28 07:37:19,902] INFO - gent.impl.patch.PatchTempFiles - Patch downloaded
[2014-05-28 07:37:19,902] INFO - impl.patch.PatchDownloaderImpl - Checking the patch is correct...
[2014-05-28 07:37:19,903] INFO - impl.patch.PatchDownloaderImpl - Patch checking finished
[2014-05-28 07:37:19,903] INFO - jetbrains.buildServer.AGENT - Patch downloaded for build with id 71238
[2014-05-28 07:37:19,919] INFO - jetbrains.buildServer.AGENT - Attempting to mark checkoutdir projectPlan for build 71238 dirty
[2014-05-28 07:37:19,919] INFO - jetbrains.buildServer.AGENT - Number of vcsRootEntries: [VcsRootEntry[VcsSettings["Project Plan" {internal id=14, properties: [externals-mode=externals-none; labelingMessage=Labeled automatically by TeamCity; labelingPatterns=trunk=>tags; secure:svn-password=*****; svn-config-directory=C:\Windows\system32\config\systemprofile\AppData\Roaming\Subversion; svn-use-default-config-directory=true; teamcity:vcsRootName=Project Plan; url=*****; user=*****; vcs=svn; working-copy-format=1.7; ]}; Checkout rules: ]]]
[2014-05-28 07:37:19,919] INFO - jetbrains.buildServer.AGENT - Recording vcs state. C: 3673, Id: 14, CR: =>
[2014-05-28 07:37:19,919] WARN - jetbrains.buildServer.AGENT - old file projectPlan.xml.old exists. Previous build might have not finished successfully
[2014-05-28 07:37:19,920] INFO - jetbrains.buildServer.AGENT - Moved configuration file projectPlan.xml to old
[2014-05-28 07:37:19,920] WARN - jetbrains.buildServer.AGENT - new file projectPlan.xml.new exists. Previous build might have not finished successfully
[2014-05-28 07:37:19,922] INFO - jetbrains.buildServer.AGENT - Stored new configuration file projectPlan.xml
[2014-05-28 07:37:19,922] INFO - .patch.UpdateSourcesFromServer - Applying patch to checkout directory...
[2014-05-28 07:37:19,931] WARN - ch.UpdateSourcesBuildStageBase - Exception occurred while patch applying: Failed to create directory: E:\BuildAgent\work\projectPlan
jetbrains.buildServer.vcs.patches.PatchException: Failed to create directory: E:\BuildAgent\work\projectPlan
at jetbrains.buildServer.vcs.patches.StrictPatcherErrorHandler.error(StrictPatcherErrorHandler.java:24)
at jetbrains.buildServer.vcs.patches.PatcherErrorHandlerBase.error(PatcherErrorHandlerBase.java:63)
at jetbrains.buildServer.vcs.patches.PatcherErrorHandlerBase.addDirectoryFailed(PatcherErrorHandlerBase.java:19)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.addDirectory(FSPatcherCallbackImpl.java:48)
at jetbrains.buildServer.vcs.patches.AbstractFSPatcher$Bridge.addDirectory(AbstractFSPatcher.java:78)
at jetbrains.buildServer.vcs.patches.AbstractPatcher$1.addDirectory(AbstractPatcher.java:60)
at jetbrains.buildServer.vcs.patches.AbstractPatcher$1.addDirectory(AbstractPatcher.java:42)
at jetbrains.buildServer.vcs.patches.LowLevelPatcher.readPatchStream(LowLevelPatcher.java:103)
at jetbrains.buildServer.vcs.patches.LowLevelPatcher.applyPatch(LowLevelPatcher.java:88)
at jetbrains.buildServer.vcs.patches.AbstractPatcher.applyPatch(AbstractPatcher.java:42)
at jetbrains.buildServer.vcs.patches.AbstractFSPatcher.applyPatch(AbstractFSPatcher.java:33)
at jetbrains.buildServer.agent.impl.patch.PatchApplierImpl.applyPatch(PatchApplierImpl.java:18)
at jetbrains.buildServer.agent.impl.patch.UpdateSourcesPatcherBase.applyPatch(UpdateSourcesPatcherBase.java:75)
at jetbrains.buildServer.agent.impl.patch.UpdateSourcesFromServer.applyPatchToDisc(UpdateSourcesFromServer.java:79)
at jetbrains.buildServer.agent.impl.patch.UpdateSourcesFromServer.updateSources(UpdateSourcesFromServer.java:65)
at jetbrains.buildServer.agent.impl.patch.UpdateSourcesBuildStageBase.doSourceUpdate(UpdateSourcesBuildStageBase.java:91)
at jetbrains.buildServer.agent.impl.patch.UpdateSourcesBuildStageBase.doRecoverableStage(UpdateSourcesBuildStageBase.java:59)
at jetbrains.buildServer.agent.impl.buildStages.startStages.RecoverableBuildStage.doBuildStage(RecoverableBuildStage.java:74)
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:78)
at jetbrains.buildServer.agent.impl.buildStages.StagesExecutor.doStages(StagesExecutor.java:37)
at jetbrains.buildServer.agent.impl.buildStages.BuildStagesExecutor.doStages(BuildStagesExecutor.java:24)
at jetbrains.buildServer.agent.impl.BuildRunAction.doStages(BuildRunAction.java:70)
at jetbrains.buildServer.agent.impl.BuildRunAction.runBuild(BuildRunAction.java:50)
at jetbrains.buildServer.agent.impl.BuildAgentImpl.doActualBuild(BuildAgentImpl.java:265)
at jetbrains.buildServer.agent.impl.BuildAgentImpl.access$100(BuildAgentImpl.java:52)
at jetbrains.buildServer.agent.impl.BuildAgentImpl$1.run(BuildAgentImpl.java:231)
at java.lang.Thread.run(Unknown Source)
Example 2:
[2014-05-27 14:44:12,585] INFO - jetbrains.buildServer.AGENT - ===================================================
[2014-05-27 14:44:12,585] INFO - jetbrains.buildServer.AGENT - Starting build buildId = 71041, buildTypeId=bt120
[2014-05-27 14:44:12,586] INFO - mpl$TeamCitySpringSubConatiner - Refreshing SubContext: running build context id=71041: startup date [Tue May 27 14:44:12 CEST 2014]; parent: jetbrains.buildServer.agent.AgentMain2$2@1271218
[2014-05-27 14:44:12,742] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.LogAgentParametersStage
[2014-05-27 14:44:12,743] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.ClearExpiredBuildWorkingDirectoriesStage
[2014-05-27 14:44:12,743] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.UpdateDirectoryMapStage
[2014-05-27 14:44:12,764] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.RegisterPropertiesFileNamesStage
[2014-05-27 14:44:12,779] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.EnableBuildStopStage
[2014-05-27 14:44:12,779] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.FireBuildStartedStage
[2014-05-27 14:44:12,797] INFO - uildServer.swabra.SwabraLogger - Swabra cleanup is disabled
[2014-05-27 14:44:12,798] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CleanAgentTempDirectoryStage
[2014-05-27 14:44:12,806] INFO - rectories.DirectoryCleanerImpl - Move directory E:\BuildAgent\temp\agentTmp to E:\BuildAgent\temp\.old\agentTmp_5 for cleaning
[2014-05-27 14:44:12,806] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateAgentTempDirectoryStage
[2014-05-27 14:44:12,807] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.PublishBuildPropertiesStage
[2014-05-27 14:44:12,824] INFO - ernalArtifactsProcessingLogger - Publishing artifacts process started
[2014-05-27 14:44:12,824] INFO - ernalArtifactsProcessingLogger - Start: Searching for artifacts to publish in [E:\BuildAgent\temp\agentTmp\build.start.properties.gz=>.teamcity/properties]
[2014-05-27 14:44:12,824] INFO - ernalArtifactsProcessingLogger - Done: Searching for artifacts to publish, found [1] file
[2014-05-27 14:44:12,824] INFO - ernalArtifactsProcessingLogger - Start: Pre-processing artifacts if needed (archiving)
[2014-05-27 14:44:12,824] INFO - ernalArtifactsProcessingLogger - Done: Pre-processing artifacts if needed (archiving)
[2014-05-27 14:44:12,824] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CleanBuildTempDirectoryStage
[2014-05-27 14:44:12,825] INFO - s.CleanBuildTempDirectoryStage - Clearing temporary directory: E:\BuildAgent\temp\buildTmp
[2014-05-27 14:44:12,829] INFO - rectories.DirectoryCleanerImpl - Move directory E:\BuildAgent\temp\buildTmp to E:\BuildAgent\temp\.old\buildTmp_5 for cleaning
[2014-05-27 14:44:12,829] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateBuildTempDirectoryStage
[2014-05-27 14:44:12,830] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateCheckoutDirectoryStage
[2014-05-27 14:44:12,833] INFO - ace.DirectoryCleanerForceClean - Free disk space under directory E:\BuildAgent\system is 136.06 GB, required 3 GB.
[2014-05-27 14:44:12,833] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CleanGeneratedFilesStage
[2014-05-27 14:44:12,833] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.LogCheckoutDirectoryStage
[2014-05-27 14:44:12,834] INFO - jetbrains.buildServer.AGENT - Checkout directory: E:\BuildAgent\work\developDaily_Test_NUnit
[2014-05-27 14:44:12,834] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.patch.UpdateSourcesFromServer
[2014-05-27 14:44:12,834] INFO - ch.UpdateSourcesBuildStageBase - Updating sources: server side checkout
[2014-05-27 14:44:12,835] INFO - .patch.UpdateSourcesFromServer - Requesting patch from server, full checkout - true
[2014-05-27 14:44:12,835] INFO - .patch.UpdateSourcesFromServer - Downloading patch to temp file...
[2014-05-27 14:44:12,835] INFO - jetbrains.buildServer.AGENT - No revision information for developDaily_Test_NUnit.xml on agent
[2014-05-27 14:44:12,839] INFO - ernalArtifactsProcessingLogger - Start: Publishing files using ArtifactsCachePublisher
[2014-05-27 14:44:12,841] INFO - ernalArtifactsProcessingLogger - Start: Publishing files using WebPublisher
[2014-05-27 14:44:12,853] INFO - ernalArtifactsProcessingLogger - Done publishing artifacts to '.teamcity/properties', using 'ArtifactsCachePublisher', total files published: 1
[2014-05-27 14:44:12,865] INFO - ernalArtifactsProcessingLogger - Done publishing artifacts to '.teamcity/properties', using 'WebPublisher', total files published: 1
[2014-05-27 14:44:12,866] INFO - ernalArtifactsProcessingLogger - Done: Publishing files
[2014-05-27 14:44:12,870] INFO - ernalArtifactsProcessingLogger - Publishing artifacts process finished
[2014-05-27 14:45:21,700] INFO - gent.impl.patch.PatchTempFiles - Patch downloaded
[2014-05-27 14:45:21,701] INFO - impl.patch.PatchDownloaderImpl - Checking the patch is correct...
[2014-05-27 14:45:21,706] INFO - impl.patch.PatchDownloaderImpl - Patch checking finished
[2014-05-27 14:45:21,706] INFO - jetbrains.buildServer.AGENT - Patch downloaded for build with id 71041
[2014-05-27 14:45:21,750] INFO - jetbrains.buildServer.AGENT - Attempting to mark checkoutdir developDaily_Test_NUnit for build 71041 dirty
[2014-05-27 14:45:21,750] INFO - jetbrains.buildServer.AGENT - Number of vcsRootEntries: [VcsRootEntry[VcsSettings["ReleaseAsset" {internal id=13, properties: [externals-mode=externals-none; labelingMessage=Labeled automatically by TeamCity; labelingPatterns=trunk=>tags; secure:svn-password=*****; svn-config-directory=C:\Windows\system32\config\systemprofile\AppData\Roaming\Subversion; svn-use-default-config-directory=true; teamcity:vcsRootName=ReleaseAsset; url=*****; user=*****; vcs=svn; working-copy-format=1.7; ]}; Checkout rules: -:.
+:1_Sources/ReleaseAsset/Test/Data
+:1_Sources/ReleaseAsset/Test/Tools]]]
[2014-05-27 14:45:21,750] INFO - jetbrains.buildServer.AGENT - Recording vcs state. C: 1471_2014/05/23 11:21:50 +0200, Id: 13, CR: 1_Sources/ReleaseAsset/Test/Tools=>1_Sources/ReleaseAsset/Test/Tools
1_Sources/ReleaseAsset/Test/Data=>1_Sources/ReleaseAsset/Test/Data
-:.
[2014-05-27 14:45:21,750] INFO - jetbrains.buildServer.AGENT - Moved configuration file developDaily_Test_NUnit.xml to old
[2014-05-27 14:45:21,751] INFO - jetbrains.buildServer.AGENT - Stored new configuration file developDaily_Test_NUnit.xml
[2014-05-27 14:45:21,752] INFO - .patch.UpdateSourcesFromServer - Applying patch to checkout directory...
[2014-05-27 14:45:22,035] WARN - ch.UpdateSourcesBuildStageBase - Exception occurred while patch applying: Failed to create directory: E:\BuildAgent\work\developDaily_Test_NUnit
jetbrains.buildServer.vcs.patches.PatchException: Failed to create directory: E:\BuildAgent\work\developDaily_Test_NUnit
at jetbrains.buildServer.vcs.patches.StrictPatcherErrorHandler.error(StrictPatcherErrorHandler.java:24)
at jetbrains.buildServer.vcs.patches.PatcherErrorHandlerBase.error(PatcherErrorHandlerBase.java:63)
at jetbrains.buildServer.vcs.patches.PatcherErrorHandlerBase.addDirectoryFailed(PatcherErrorHandlerBase.java:19)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.addDirectory(FSPatcherCallbackImpl.java:48)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.ensureParentFolder(FSPatcherCallbackImpl.java:145)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.addDirectory(FSPatcherCallbackImpl.java:30)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.ensureParentFolder(FSPatcherCallbackImpl.java:145)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.addDirectory(FSPatcherCallbackImpl.java:30)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.ensureParentFolder(FSPatcherCallbackImpl.java:145)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.addDirectory(FSPatcherCallbackImpl.java:30)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.ensureParentFolder(FSPatcherCallbackImpl.java:145)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.addDirectory(FSPatcherCallbackImpl.java:30)
at jetbrains.buildServer.vcs.patches.AbstractFSPatcher$Bridge.addDirectory(AbstractFSPatcher.java:78)
at jetbrains.buildServer.vcs.patches.AbstractPatcher$1.addDirectory(AbstractPatcher.java:60)
at jetbrains.buildServer.vcs.patches.AbstractPatcher$1.addDirectory(AbstractPatcher.java:42)
at jetbrains.buildServer.vcs.patches.LowLevelPatcher.readPatchStream(LowLevelPatcher.java:103)
at jetbrains.buildServer.vcs.patches.LowLevelPatcher.applyPatch(LowLevelPatcher.java:88)
at jetbrains.buildServer.vcs.patches.AbstractPatcher.applyPatch(AbstractPatcher.java:42)
at jetbrains.buildServer.vcs.patches.AbstractFSPatcher.applyPatch(AbstractFSPatcher.java:33)
at jetbrains.buildServer.agent.impl.patch.PatchApplierImpl.applyPatch(PatchApplierImpl.java:18)
at jetbrains.buildServer.agent.impl.patch.UpdateSourcesPatcherBase.applyPatch(UpdateSourcesPatcherBase.java:75)
at jetbrains.buildServer.agent.impl.patch.UpdateSourcesFromServer.applyPatchToDisc(UpdateSourcesFromServer.java:79)
at jetbrains.buildServer.agent.impl.patch.UpdateSourcesFromServer.updateSources(UpdateSourcesFromServer.java:65)
at jetbrains.buildServer.agent.impl.patch.UpdateSourcesBuildStageBase.doSourceUpdate(UpdateSourcesBuildStageBase.java:91)
at jetbrains.buildServer.agent.impl.patch.UpdateSourcesBuildStageBase.doRecoverableStage(UpdateSourcesBuildStageBase.java:59)
at jetbrains.buildServer.agent.impl.buildStages.startStages.RecoverableBuildStage.doBuildStage(RecoverableBuildStage.java:74)
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:78)
at jetbrains.buildServer.agent.impl.buildStages.StagesExecutor.doStages(StagesExecutor.java:37)
at jetbrains.buildServer.agent.impl.buildStages.BuildStagesExecutor.doStages(BuildStagesExecutor.java:24)
at jetbrains.buildServer.agent.impl.BuildRunAction.doStages(BuildRunAction.java:70)
at jetbrains.buildServer.agent.impl.BuildRunAction.runBuild(BuildRunAction.java:50)
at jetbrains.buildServer.agent.impl.BuildAgentImpl.doActualBuild(BuildAgentImpl.java:265)
at jetbrains.buildServer.agent.impl.BuildAgentImpl.access$100(BuildAgentImpl.java:52)
at jetbrains.buildServer.agent.impl.BuildAgentImpl$1.run(BuildAgentImpl.java:231)
at java.lang.Thread.run(Unknown Source)
buildAgent process cannot create a folder for checkout directory. In most cases, it's a problem with permissions - please double check that.
Just checked the permissions again but that shouldn't be the problem. The permissions on the Agent's work directory and it's sub-directories is set to Read/Write for the user role "Everyone". The Agent is started via the batch file from the bin directory and thus runs with the permissions of the logged on user who is both in the Users group and the Administrators group of the machine.
Please try to replace TC/webapps/ROOT/update/buildAgent.zip with this one: ftp://ftp.intellij.net/pub/.teamcity/addDirectoryLogged/buildAgent.zip. It has some logging enabled. Agents should update automatically.
Alright thanks, the Agents are just in the process of updating. I'll post the log entries after issue has occurred again!
Got quite a number of new errors during the couple last days but I wasn't able to post a new log until today... Here's a new log entry for the error (although I don't recognize any additional log messages?):
[2014-06-02 06:42:24,843] INFO - jetbrains.buildServer.AGENT - ===================================================
[2014-06-02 06:42:24,843] INFO - jetbrains.buildServer.AGENT - Starting build buildId = 71691, buildTypeId=bt53
[2014-06-02 06:42:24,844] INFO - mpl$TeamCitySpringSubConatiner - Refreshing SubContext: running build context id=71691: startup date [Mon Jun 02 06:42:24 CEST 2014]; parent: jetbrains.buildServer.agent.AgentMain2$2@1271218
[2014-06-02 06:42:24,946] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.LogAgentParametersStage
[2014-06-02 06:42:24,946] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.ClearExpiredBuildWorkingDirectoriesStage
[2014-06-02 06:42:24,946] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.UpdateDirectoryMapStage
[2014-06-02 06:42:24,968] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.RegisterPropertiesFileNamesStage
[2014-06-02 06:42:24,972] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.EnableBuildStopStage
[2014-06-02 06:42:24,972] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.FireBuildStartedStage
[2014-06-02 06:42:24,978] INFO - uildServer.swabra.SwabraLogger - Swabra cleanup is disabled
[2014-06-02 06:42:24,978] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CleanAgentTempDirectoryStage
[2014-06-02 06:42:24,993] INFO - rectories.DirectoryCleanerImpl - Move directory C:\BuildAgent\temp\agentTmp to C:\BuildAgent\temp\.old\agentTmp_0 for cleaning
[2014-06-02 06:42:24,993] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateAgentTempDirectoryStage
[2014-06-02 06:42:24,993] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.PublishBuildPropertiesStage
[2014-06-02 06:42:25,002] INFO - ernalArtifactsProcessingLogger - Publishing artifacts process started
[2014-06-02 06:42:25,002] INFO - ernalArtifactsProcessingLogger - Start: Searching for artifacts to publish in [C:\BuildAgent\temp\agentTmp\build.start.properties.gz=>.teamcity/properties]
[2014-06-02 06:42:25,002] INFO - ernalArtifactsProcessingLogger - Done: Searching for artifacts to publish, found [1] file
[2014-06-02 06:42:25,002] INFO - ernalArtifactsProcessingLogger - Start: Pre-processing artifacts if needed (archiving)
[2014-06-02 06:42:25,002] INFO - ernalArtifactsProcessingLogger - Done: Pre-processing artifacts if needed (archiving)
[2014-06-02 06:42:25,002] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CleanBuildTempDirectoryStage
[2014-06-02 06:42:25,002] INFO - s.CleanBuildTempDirectoryStage - Clearing temporary directory: C:\BuildAgent\temp\buildTmp
[2014-06-02 06:42:25,010] INFO - rectories.DirectoryCleanerImpl - Move directory C:\BuildAgent\temp\buildTmp to C:\BuildAgent\temp\.old\buildTmp_0 for cleaning
[2014-06-02 06:42:25,010] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateBuildTempDirectoryStage
[2014-06-02 06:42:25,010] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateCheckoutDirectoryStage
[2014-06-02 06:42:25,012] INFO - ace.DirectoryCleanerForceClean - Free disk space under directory C:\BuildAgent\system is 74.73 GB, required 3 GB.
[2014-06-02 06:42:25,012] INFO - ace.DirectoryCleanerForceClean - Free disk space under directory D:\BuildAgent\work\developDailyCppUnitTest is 194.22 GB, required 3 GB.
[2014-06-02 06:42:25,012] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CleanGeneratedFilesStage
[2014-06-02 06:42:25,012] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.LogCheckoutDirectoryStage
[2014-06-02 06:42:25,012] INFO - jetbrains.buildServer.AGENT - Checkout directory: D:\BuildAgent\work\developDailyCppUnitTest
[2014-06-02 06:42:25,013] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.patch.UpdateSourcesFromServer
[2014-06-02 06:42:25,013] INFO - ch.UpdateSourcesBuildStageBase - Updating sources: server side checkout
[2014-06-02 06:42:25,013] INFO - .patch.UpdateSourcesFromServer - Requesting patch from server, full checkout - true
[2014-06-02 06:42:25,013] INFO - .patch.UpdateSourcesFromServer - Downloading patch to temp file...
[2014-06-02 06:42:25,013] INFO - jetbrains.buildServer.AGENT - No revision information for developDailyCppUnitTest.xml on agent
[2014-06-02 06:42:25,079] INFO - ernalArtifactsProcessingLogger - Start: Publishing files using WebPublisher
[2014-06-02 06:42:25,082] INFO - ernalArtifactsProcessingLogger - Start: Publishing files using ArtifactsCachePublisher
[2014-06-02 06:42:25,138] INFO - ernalArtifactsProcessingLogger - Done publishing artifacts to '.teamcity/properties', using 'WebPublisher', total files published: 1
[2014-06-02 06:42:25,138] INFO - ernalArtifactsProcessingLogger - Done publishing artifacts to '.teamcity/properties', using 'ArtifactsCachePublisher', total files published: 1
[2014-06-02 06:42:25,138] INFO - ernalArtifactsProcessingLogger - Done: Publishing files
[2014-06-02 06:42:25,141] INFO - ernalArtifactsProcessingLogger - Publishing artifacts process finished
[2014-06-02 06:44:00,559] INFO - gent.impl.patch.PatchTempFiles - Patch downloaded
[2014-06-02 06:44:00,559] INFO - impl.patch.PatchDownloaderImpl - Checking the patch is correct...
[2014-06-02 06:44:00,563] INFO - impl.patch.PatchDownloaderImpl - Patch checking finished
[2014-06-02 06:44:00,563] INFO - jetbrains.buildServer.AGENT - Patch downloaded for build with id 71691
[2014-06-02 06:44:00,728] INFO - jetbrains.buildServer.AGENT - Attempting to mark checkoutdir developDailyCppUnitTest for build 71691 dirty
[2014-06-02 06:44:00,728] INFO - jetbrains.buildServer.AGENT - Number of vcsRootEntries: [VcsRootEntry[VcsSettings["ScanSoftware" {internal id=34, properties: [externals-mode=externals-full; labelingMessage=Labeled automatically by TeamCity; labelingPatterns=trunk=>tags; secure:svn-password=*****; svn-config-directory=C:\Windows\system32\config\systemprofile\AppData\Roaming\Subversion; svn-use-default-config-directory=true; teamcity:branchSpec=; teamcity:vcsRootName=ScanSoftware; url=*****; user=*****; vcs=svn; working-copy-format=1.7; ]}; Checkout rules: +:1_Sources\ScanSoftware\Testsupport]]]
[2014-06-02 06:44:00,728] INFO - jetbrains.buildServer.AGENT - Recording vcs state. C: 37945_2014/05/28 12:16:34 +0200, Id: 34, CR: 1_Sources/ScanSoftware/Testsupport=>1_Sources/ScanSoftware/Testsupport
[2014-06-02 06:44:00,728] INFO - jetbrains.buildServer.AGENT - Moved configuration file developDailyCppUnitTest.xml to old
[2014-06-02 06:44:00,729] INFO - jetbrains.buildServer.AGENT - Stored new configuration file developDailyCppUnitTest.xml
[2014-06-02 06:44:00,729] INFO - .patch.UpdateSourcesFromServer - Applying patch to checkout directory...
[2014-06-02 06:44:00,751] WARN - ch.UpdateSourcesBuildStageBase - Exception occurred while patch applying: Failed to create directory: D:\BuildAgent\work\developDailyCppUnitTest
jetbrains.buildServer.vcs.patches.PatchException: Failed to create directory: D:\BuildAgent\work\developDailyCppUnitTest
at jetbrains.buildServer.vcs.patches.StrictPatcherErrorHandler.error(StrictPatcherErrorHandler.java:24)
at jetbrains.buildServer.vcs.patches.PatcherErrorHandlerBase.error(PatcherErrorHandlerBase.java:63)
at jetbrains.buildServer.vcs.patches.PatcherErrorHandlerBase.addDirectoryFailed(PatcherErrorHandlerBase.java:19)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.addDirectory(FSPatcherCallbackImpl.java:48)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.ensureParentFolder(FSPatcherCallbackImpl.java:145)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.addDirectory(FSPatcherCallbackImpl.java:30)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.ensureParentFolder(FSPatcherCallbackImpl.java:145)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.addDirectory(FSPatcherCallbackImpl.java:30)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.ensureParentFolder(FSPatcherCallbackImpl.java:145)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.addDirectory(FSPatcherCallbackImpl.java:30)
at jetbrains.buildServer.vcs.patches.AbstractFSPatcher$Bridge.addDirectory(AbstractFSPatcher.java:78)
at jetbrains.buildServer.vcs.patches.AbstractPatcher$1.addDirectory(AbstractPatcher.java:60)
at jetbrains.buildServer.vcs.patches.AbstractPatcher$1.addDirectory(AbstractPatcher.java:42)
at jetbrains.buildServer.vcs.patches.LowLevelPatcher.readPatchStream(LowLevelPatcher.java:103)
at jetbrains.buildServer.vcs.patches.LowLevelPatcher.applyPatch(LowLevelPatcher.java:88)
at jetbrains.buildServer.vcs.patches.AbstractPatcher.applyPatch(AbstractPatcher.java:42)
at jetbrains.buildServer.vcs.patches.AbstractFSPatcher.applyPatch(AbstractFSPatcher.java:33)
at jetbrains.buildServer.agent.impl.patch.PatchApplierImpl.applyPatch(PatchApplierImpl.java:18)
at jetbrains.buildServer.agent.impl.patch.UpdateSourcesPatcherBase.applyPatch(UpdateSourcesPatcherBase.java:75)
at jetbrains.buildServer.agent.impl.patch.UpdateSourcesFromServer.applyPatchToDisc(UpdateSourcesFromServer.java:79)
at jetbrains.buildServer.agent.impl.patch.UpdateSourcesFromServer.updateSources(UpdateSourcesFromServer.java:65)
at jetbrains.buildServer.agent.impl.patch.UpdateSourcesBuildStageBase.doSourceUpdate(UpdateSourcesBuildStageBase.java:91)
at jetbrains.buildServer.agent.impl.patch.UpdateSourcesBuildStageBase.doRecoverableStage(UpdateSourcesBuildStageBase.java:59)
at jetbrains.buildServer.agent.impl.buildStages.startStages.RecoverableBuildStage.doBuildStage(RecoverableBuildStage.java:74)
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:78)
at jetbrains.buildServer.agent.impl.buildStages.StagesExecutor.doStages(StagesExecutor.java:37)
at jetbrains.buildServer.agent.impl.buildStages.BuildStagesExecutor.doStages(BuildStagesExecutor.java:24)
at jetbrains.buildServer.agent.impl.BuildRunAction.doStages(BuildRunAction.java:70)
at jetbrains.buildServer.agent.impl.BuildRunAction.runBuild(BuildRunAction.java:50)
at jetbrains.buildServer.agent.impl.BuildAgentImpl.doActualBuild(BuildAgentImpl.java:265)
at jetbrains.buildServer.agent.impl.BuildAgentImpl.access$100(BuildAgentImpl.java:52)
at jetbrains.buildServer.agent.impl.BuildAgentImpl$1.run(BuildAgentImpl.java:231)
at java.lang.Thread.run(Unknown Source)
Oh, I forgot to add that you need to restart the server to let agents grab the new file.
Hmm the server has been restarted last friday so that shouldn't be the issue. Any other idea what might have gone wrong?
This is magic. How does your buildAgent.properties file look like?
Also, do you see attempts to restart in teamcity-agent.log for upgrade?
The upgrade seems to have been completed successfully according to the agent log:
[2014-05-28 17:59:55,952] INFO - jetbrains.buildServer.AGENT - Upgrade call received from the build server
[2014-05-28 17:59:55,953] INFO - jetbrains.buildServer.AGENT - Will upgrade when become idle
[2014-05-28 17:59:55,953] INFO - jetbrains.buildServer.AGENT - Wait for build agent registration to finish
[2014-05-28 17:59:55,954] INFO - jetbrains.buildServer.AGENT - Registration of build agent is finished.
[2014-05-28 17:59:55,954] INFO - jetbrains.buildServer.AGENT - Stop command was not performed. No build to stop with reason: BuildInterruptReason.AGENT_SHUTDOWN
[2014-05-28 17:59:55,954] INFO - jetbrains.buildServer.AGENT - Starting agent shutdown sequence, reason: Restart agent, failed to download upgrade from server
[2014-05-28 17:59:55,958] INFO - jetbrains.buildServer.AGENT - Host configuration for downloading updates: HostConfiguration[host=*****]
[2014-05-28 17:59:55,958] INFO - jetbrains.buildServer.AGENT - Downloading *****/update/teamcity-agent.xml ==> C:\BuildAgent\temp\uW9qNGgaQoolmh0ShUOhPMh5UnBdhkGL
[2014-05-28 17:59:55,959] INFO - agent.impl.AgentPortFileWriter - Delete agent runtime file from C:\BuildAgent\logs\buildAgent.port
[2014-05-28 17:59:55,960] INFO - jetbrains.buildServer.AGENT - Unregistering from the server. Agent id: 18
[2014-05-28 17:59:55,964] INFO - jetbrains.buildServer.AGENT - Downloading *****/update/buildAgent.zip ==> C:\BuildAgent\update\buildAgent.zip
[2014-05-28 17:59:55,983] INFO - jetbrains.buildServer.AGENT - Shutdown agent WebServer start
[2014-05-28 17:59:55,983] INFO - jetbrains.buildServer.AGENT - Shutdown agent WebServer finish
[2014-05-28 17:59:55,983] INFO - jetbrains.buildServer.AGENT - Shutdown agent finish
[2014-05-28 17:59:56,500] INFO - jetbrains.buildServer.AGENT - Upgrade mode: jetbrains.buildServer.agent.impl.upgrade.modes.AgentOnlyUpgradeMode
[2014-05-28 17:59:56,500] INFO - rocesses.ProcessTreeTerminator - Using jetbrains.buildServer.processes.ProcessTreeTerminatorWindows
[2014-05-28 17:59:56,531] INFO - .ProcessTreeTerminatorImplBase - No processes to kill
[2014-05-28 17:59:56,532] INFO - jetbrains.buildServer.AGENT - Exit for upgrade
[2014-05-28 17:59:56,532] INFO - ent.impl.upgrade.AgentExitCode - Agent exited. Upgrade process
[2014-05-28 17:59:56,533] INFO - buildServer.agent.AgentMain2$2 - Closing jetbrains.buildServer.agent.AgentMain2$2@150b2d: startup date [Tue May 27 15:55:27 CEST 2014]; root of context hierarchy
[2014-05-30 08:27:42,957] INFO - jetbrains.buildServer.SERVER - Starting TeamCity agent
[2014-05-30 08:27:42,958] INFO - s.buildServer.agent.AgentMain2 -
[2014-05-30 08:27:42,958] INFO - s.buildServer.agent.AgentMain2 - ===========================================================
[2014-05-30 08:27:42,976] INFO - s.buildServer.agent.AgentMain2 - TeamCity Build Agent 8.1.2 (build 29993), OS: Windows 7, JRE: 1.7.0_21-b11 Java HotSpot(TM) Client VM, JVM parameters: -ea -Xmx384m -Dlog4j.configuration=file:../conf/teamcity-agent-log4j.xml -Dteamcity_logs=../logs/
[2014-05-30 08:27:42,976] INFO - s.buildServer.agent.AgentMain2 - Starting...
[2014-05-30 08:27:42,987] INFO - s.buildServer.agent.AgentMain2 - Agent home is C:\BuildAgent
[2014-05-30 08:27:43,042] INFO - buildServer.agent.AgentMain2$2 - Refreshing jetbrains.buildServer.agent.AgentMain2$2@1271218: startup date [Fri May 30 08:27:43 CEST 2014]; root of context hierarchy
The Build Agent properties file looks like this:
#Generated properties (see buildAgent.dist.properties for description)
#Wed Jul 24 08:45:17 CEST 2013
name=Monster
ownPort=9090
serverUrl=*****
workDir=D\:\\BuildAgent\\work
tempDir=C\:\\BuildAgent\\temp
#User defined properties
#Wed Jul 24 08:45:17 CEST 2013
env.TEAMCITY_JRE=C\:\\BuildAgent\\jre
authorizationToken=*****
Hmm well ok seems that the upgrade didn't work out for this specific agent, at least the agent upgrade.log file doesn't mention any upgrade while all of the other agents seem to have upgraded successfully... Is there any way I can retrigger the upgrade for this agent?
After setting up the agent again using the zip file from the "Install Build Agent" Link the agent was now able to upgrade successfully. I'll wait until the error happens again and hope that the extended logging functionality now works.
I replaced the buildAgent.zip with another one ftp://ftp.intellij.net/pub/.teamcity/addDirectoryLogged/buildAgent.zip. Please put it to the webapps/ROOT/WEB-INF/update/
Hmm, this is bad. Can you please grab all log directory from this agent and attach here. Builds shouldn't run on outdated agent.
Ok the error just happened again and this time it seems that some additional messages were logged:
[2014-06-04 14:57:54,948] INFO - jetbrains.buildServer.AGENT - ===================================================
[2014-06-04 14:57:54,948] INFO - jetbrains.buildServer.AGENT - Starting build buildId = 72452, buildTypeId=bt103
[2014-06-04 14:57:54,948] INFO - mpl$TeamCitySpringSubConatiner - Refreshing SubContext: running build context id=72452: startup date [Wed Jun 04 14:57:54 CEST 2014]; parent: jetbrains.buildServer.agent.AgentMain2$2@181c87
[2014-06-04 14:57:55,055] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.LogAgentParametersStage
[2014-06-04 14:57:55,056] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.ClearExpiredBuildWorkingDirectoriesStage
[2014-06-04 14:57:55,056] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.UpdateDirectoryMapStage
[2014-06-04 14:57:55,080] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.RegisterPropertiesFileNamesStage
[2014-06-04 14:57:55,085] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.EnableBuildStopStage
[2014-06-04 14:57:55,085] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.FireBuildStartedStage
[2014-06-04 14:57:55,089] INFO - uildServer.swabra.SwabraLogger - Swabra cleanup is disabled
[2014-06-04 14:57:55,090] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CleanAgentTempDirectoryStage
[2014-06-04 14:57:55,097] INFO - rectories.DirectoryCleanerImpl - Move directory C:\BuildAgent\temp\agentTmp to C:\BuildAgent\temp\.old\agentTmp_0 for cleaning
[2014-06-04 14:57:55,097] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateAgentTempDirectoryStage
[2014-06-04 14:57:55,097] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.PublishBuildPropertiesStage
[2014-06-04 14:57:55,104] INFO - ernalArtifactsProcessingLogger - Publishing artifacts process started
[2014-06-04 14:57:55,104] INFO - ernalArtifactsProcessingLogger - Start: Searching for artifacts to publish in [C:\BuildAgent\temp\agentTmp\build.start.properties.gz=>.teamcity/properties]
[2014-06-04 14:57:55,104] INFO - ernalArtifactsProcessingLogger - Done: Searching for artifacts to publish, found [1] file
[2014-06-04 14:57:55,104] INFO - ernalArtifactsProcessingLogger - Start: Pre-processing artifacts if needed (archiving)
[2014-06-04 14:57:55,104] INFO - ernalArtifactsProcessingLogger - Done: Pre-processing artifacts if needed (archiving)
[2014-06-04 14:57:55,104] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CleanBuildTempDirectoryStage
[2014-06-04 14:57:55,104] INFO - s.CleanBuildTempDirectoryStage - Clearing temporary directory: C:\BuildAgent\temp\buildTmp
[2014-06-04 14:57:55,108] INFO - rectories.DirectoryCleanerImpl - Move directory C:\BuildAgent\temp\buildTmp to C:\BuildAgent\temp\.old\buildTmp_0 for cleaning
[2014-06-04 14:57:55,108] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateBuildTempDirectoryStage
[2014-06-04 14:57:55,109] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.DirtySourcesIfCleanBuildStage
[2014-06-04 14:57:55,109] INFO - jetbrains.buildServer.AGENT - Patch downloaded for build with id 72452
[2014-06-04 14:57:55,113] INFO - ernalArtifactsProcessingLogger - Start: Publishing files using WebPublisher
[2014-06-04 14:57:55,115] INFO - ernalArtifactsProcessingLogger - Start: Publishing files using ArtifactsCachePublisher
[2014-06-04 14:57:55,143] INFO - ernalArtifactsProcessingLogger - Done publishing artifacts to '.teamcity/properties', using 'WebPublisher', total files published: 1
[2014-06-04 14:57:55,143] INFO - ernalArtifactsProcessingLogger - Done publishing artifacts to '.teamcity/properties', using 'ArtifactsCachePublisher', total files published: 1
[2014-06-04 14:57:55,143] INFO - ernalArtifactsProcessingLogger - Done: Publishing files
[2014-06-04 14:57:55,148] INFO - ernalArtifactsProcessingLogger - Publishing artifacts process finished
[2014-06-04 14:57:55,179] INFO - jetbrains.buildServer.AGENT - Attempting to mark checkoutdir developNightly_32bit for build 72452 dirty
[2014-06-04 14:57:55,179] INFO - jetbrains.buildServer.AGENT - Number of vcsRootEntries: [VcsRootEntry[VcsSettings["ScanSoftware" {internal id=53, properties: [externals-mode=externals-full; labelingMessage=Labeled automatically by TeamCity; labelingPatterns=trunk=>tags; secure:svn-password=*****; svn-config-directory=C:\Windows\system32\config\systemprofile\AppData\Roaming\Subversion; svn-use-default-config-directory=true; teamcity:vcsRootName=ScanSoftware; url=*****; user=*****; vcs=svn; working-copy-format=1.8; ]}; Checkout rules: -:.
+:1_Sources]]]
[2014-06-04 14:57:55,179] INFO - jetbrains.buildServer.AGENT - No revision information for developNightly_32bit.xml on agent
[2014-06-04 14:57:55,180] INFO - jetbrains.buildServer.AGENT - Recording vcs state. C: 38012_2014/06/04 14:57:27 +0200, Id: 1_svn_2373396656266921473_959179572, CR: 1_Sources=>1_Sources
-:.
[2014-06-04 14:57:55,180] INFO - jetbrains.buildServer.AGENT - Moved configuration file developNightly_32bit.xml to old
[2014-06-04 14:57:55,180] INFO - jetbrains.buildServer.AGENT - Stored new configuration file developNightly_32bit.xml
[2014-06-04 14:57:55,181] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CleanBuildCheckoutDirectoryIfNeededStage
[2014-06-04 14:57:55,181] INFO - CheckoutDirectoryIfNeededStage - Clean build enabled: removing old files from D:\BuildAgent\work\developNightly_32bit
[2014-06-04 14:57:55,184] INFO - rectories.DirectoryCleanerImpl - Move directory D:\BuildAgent\work\developNightly_32bit to D:\BuildAgent\work\.old\developNightly_32bit_0 for cleaning
[2014-06-04 14:57:55,184] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateCheckoutDirectoryStage
[2014-06-04 14:57:55,188] INFO - ace.DirectoryCleanerForceClean - Free disk space under directory C:\BuildAgent\system is 36.87 GB, required 30 GB.
[2014-06-04 14:57:55,188] INFO - ace.DirectoryCleanerForceClean - Free disk space under directory D:\BuildAgent\work\developNightly_32bit is 130.5 GB, required 30 GB.
[2014-06-04 14:57:55,188] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CleanGeneratedFilesStage
[2014-06-04 14:57:55,188] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.LogCheckoutDirectoryStage
[2014-06-04 14:57:55,188] INFO - jetbrains.buildServer.AGENT - Checkout directory: D:\BuildAgent\work\developNightly_32bit. Exists: true
[2014-06-04 14:57:55,189] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.patch.UpdateSourcesFromServer
[2014-06-04 14:57:55,189] INFO - ch.UpdateSourcesBuildStageBase - Updating sources: server side checkout
[2014-06-04 14:57:55,189] INFO - .patch.UpdateSourcesFromServer - Requesting patch from server, full checkout - true
[2014-06-04 14:57:55,189] INFO - .patch.UpdateSourcesFromServer - Downloading patch to temp file...
[2014-06-04 14:57:55,189] INFO - .patch.UpdateSourcesFromServer -
Checking folders....
[2014-06-04 14:57:55,189] INFO - .patch.UpdateSourcesFromServer - Checkout directory: 'D:\BuildAgent\work\developNightly_32bit'. Exists: true
[2014-06-04 14:57:55,189] INFO - .patch.UpdateSourcesFromServer - Checkout directory exists. Skipping pre-test
[2014-06-04 15:00:09,065] INFO - gent.impl.patch.PatchTempFiles - Patch downloaded
[2014-06-04 15:00:09,065] INFO - impl.patch.PatchDownloaderImpl - Checking the patch is correct...
[2014-06-04 15:00:09,347] INFO - impl.patch.PatchDownloaderImpl - Patch checking finished
[2014-06-04 15:00:09,347] INFO - jetbrains.buildServer.AGENT - Patch downloaded for build with id 72452
[2014-06-04 15:00:09,361] INFO - jetbrains.buildServer.AGENT - Attempting to mark checkoutdir developNightly_32bit for build 72452 dirty
[2014-06-04 15:00:09,361] INFO - jetbrains.buildServer.AGENT - Number of vcsRootEntries: [VcsRootEntry[VcsSettings["ScanSoftware" {internal id=53, properties: [externals-mode=externals-full; labelingMessage=Labeled automatically by TeamCity; labelingPatterns=trunk=>tags; secure:svn-password=*****; svn-config-directory=C:\Windows\system32\config\systemprofile\AppData\Roaming\Subversion; svn-use-default-config-directory=true; teamcity:vcsRootName=ScanSoftware; url=*****; user=*****; vcs=svn; working-copy-format=1.8; ]}; Checkout rules: -:.
+:1_Sources]]]
[2014-06-04 15:00:09,361] INFO - jetbrains.buildServer.AGENT - Recording vcs state. C: 38012_2014/06/04 14:57:27 +0200, Id: 1_svn_2373396656266921473_959179572, CR: 1_Sources=>1_Sources
-:.
[2014-06-04 15:00:09,361] INFO - jetbrains.buildServer.AGENT - Moved configuration file developNightly_32bit.xml to old
[2014-06-04 15:00:09,361] WARN - jetbrains.buildServer.AGENT - new file developNightly_32bit.xml.new exists. Previous build might have not finished successfully
[2014-06-04 15:00:09,362] INFO - jetbrains.buildServer.AGENT - Stored new configuration file developNightly_32bit.xml
[2014-06-04 15:00:09,362] INFO - .patch.UpdateSourcesFromServer - Applying patch to checkout directory...
[2014-06-04 15:00:09,363] ERROR - .patches.FSPatcherCallbackImpl - Add directory failed. Dir created: false
Child dirs: [.old, 108d35aafa48a6e7, 800be6fe22d17549, bc83a1ad7458f477, cf6ea03feacc5b72, developDaily, developDailyReleaseAsset, developDaily_Test_NUnit_UI, developNightlyDebug_32bit, developNightlyDebug_64bit, developNightlyReleaseAsset, developNightlyRunJavaGuiTests, developNightlyJavaGuiTests, developNightly_32bit, developNightly_64bit, directory.map, e688a90c0dfcd390, f180e3b4dbb31335, faf10ef27d2e3022, Python, 5.3Debug_32bit, 5.3Debug_64bit, 5.3ReleaseAsset, 5.3ReportJavaGuiTests, 5.3RunJavaGuiTests, 5.3JavaGuiTests, CT5.3]
[2014-06-04 15:00:09,819] WARN - ch.UpdateSourcesBuildStageBase - Exception occurred while patch applying: Failed to create directory: D:\BuildAgent\work\developNightly_32bit
jetbrains.buildServer.vcs.patches.PatchException: Failed to create directory: D:\BuildAgent\work\developNightly_32bit
at jetbrains.buildServer.vcs.patches.StrictPatcherErrorHandler.error(StrictPatcherErrorHandler.java:24)
at jetbrains.buildServer.vcs.patches.PatcherErrorHandlerBase.error(PatcherErrorHandlerBase.java:63)
at jetbrains.buildServer.vcs.patches.PatcherErrorHandlerBase.addDirectoryFailed(PatcherErrorHandlerBase.java:19)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.addDirectory(FSPatcherCallbackImpl.java:57)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.ensureParentFolder(FSPatcherCallbackImpl.java:154)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.addDirectory(FSPatcherCallbackImpl.java:31)
at jetbrains.buildServer.vcs.patches.AbstractFSPatcher$Bridge.addDirectory(AbstractFSPatcher.java:78)
at jetbrains.buildServer.vcs.patches.AbstractPatcher$1.addDirectory(AbstractPatcher.java:60)
at jetbrains.buildServer.vcs.patches.AbstractPatcher$1.addDirectory(AbstractPatcher.java:42)
at jetbrains.buildServer.vcs.patches.LowLevelPatcher.readPatchStream(LowLevelPatcher.java:103)
at jetbrains.buildServer.vcs.patches.LowLevelPatcher.applyPatch(LowLevelPatcher.java:88)
at jetbrains.buildServer.vcs.patches.AbstractPatcher.applyPatch(AbstractPatcher.java:42)
at jetbrains.buildServer.vcs.patches.AbstractFSPatcher.applyPatch(AbstractFSPatcher.java:33)
at jetbrains.buildServer.agent.impl.patch.PatchApplierImpl.applyPatch(PatchApplierImpl.java:18)
at jetbrains.buildServer.agent.impl.patch.UpdateSourcesPatcherBase.applyPatch(UpdateSourcesPatcherBase.java:75)
at jetbrains.buildServer.agent.impl.patch.UpdateSourcesFromServer.applyPatchToDisc(UpdateSourcesFromServer.java:101)
at jetbrains.buildServer.agent.impl.patch.UpdateSourcesFromServer.updateSources(UpdateSourcesFromServer.java:87)
at jetbrains.buildServer.agent.impl.patch.UpdateSourcesBuildStageBase.doSourceUpdate(UpdateSourcesBuildStageBase.java:91)
at jetbrains.buildServer.agent.impl.patch.UpdateSourcesBuildStageBase.doRecoverableStage(UpdateSourcesBuildStageBase.java:59)
at jetbrains.buildServer.agent.impl.buildStages.startStages.RecoverableBuildStage.doBuildStage(RecoverableBuildStage.java:74)
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:78)
at jetbrains.buildServer.agent.impl.buildStages.StagesExecutor.doStages(StagesExecutor.java:37)
at jetbrains.buildServer.agent.impl.buildStages.BuildStagesExecutor.doStages(BuildStagesExecutor.java:24)
at jetbrains.buildServer.agent.impl.BuildRunAction.doStages(BuildRunAction.java:70)
at jetbrains.buildServer.agent.impl.BuildRunAction.runBuild(BuildRunAction.java:50)
at jetbrains.buildServer.agent.impl.BuildAgentImpl.doActualBuild(BuildAgentImpl.java:265)
at jetbrains.buildServer.agent.impl.BuildAgentImpl.access$100(BuildAgentImpl.java:52)
at jetbrains.buildServer.agent.impl.BuildAgentImpl$1.run(BuildAgentImpl.java:231)
at java.lang.Thread.run(Thread.java:745)
Do you have multiple buildAgents on the same machine or multiple buildAgents share the same working directory?
As far as I can see, the directory was present, but then disappeared
[2014-06-04 14:57:55,188] INFO - jetbrains.buildServer.AGENT - Checkout directory: D:\BuildAgent\work\developNightly_32bit. Exists: true
No, there is definitly only one build agent running on those machines that have this problem. Anything else I could check?
Here's another log entry for a different project. Probably nothing new to see there though.
[2014-06-07 06:44:47,408] INFO - jetbrains.buildServer.AGENT - ===================================================
[2014-06-07 06:44:47,408] INFO - jetbrains.buildServer.AGENT - Starting build buildId = 73105, buildTypeId=bt53
[2014-06-07 06:44:47,408] INFO - mpl$TeamCitySpringSubConatiner - Refreshing SubContext: running build context id=73105: startup date [Sat Jun 07 06:44:47 CEST 2014]; parent: jetbrains.buildServer.agent.AgentMain2$2@181c87
[2014-06-07 06:44:47,511] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.LogAgentParametersStage
[2014-06-07 06:44:47,512] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.ClearExpiredBuildWorkingDirectoriesStage
[2014-06-07 06:44:47,512] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.UpdateDirectoryMapStage
[2014-06-07 06:44:47,530] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.RegisterPropertiesFileNamesStage
[2014-06-07 06:44:47,535] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.EnableBuildStopStage
[2014-06-07 06:44:47,536] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.FireBuildStartedStage
[2014-06-07 06:44:47,541] INFO - uildServer.swabra.SwabraLogger - Swabra cleanup is disabled
[2014-06-07 06:44:47,541] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CleanAgentTempDirectoryStage
[2014-06-07 06:44:47,552] INFO - rectories.DirectoryCleanerImpl - Move directory C:\BuildAgent\temp\agentTmp to C:\BuildAgent\temp\.old\agentTmp_1 for cleaning
[2014-06-07 06:44:47,552] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateAgentTempDirectoryStage
[2014-06-07 06:44:47,553] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.PublishBuildPropertiesStage
[2014-06-07 06:44:47,561] INFO - ernalArtifactsProcessingLogger - Publishing artifacts process started
[2014-06-07 06:44:47,561] INFO - ernalArtifactsProcessingLogger - Start: Searching for artifacts to publish in [C:\BuildAgent\temp\agentTmp\build.start.properties.gz=>.teamcity/properties]
[2014-06-07 06:44:47,561] INFO - ernalArtifactsProcessingLogger - Done: Searching for artifacts to publish, found [1] file
[2014-06-07 06:44:47,561] INFO - ernalArtifactsProcessingLogger - Start: Pre-processing artifacts if needed (archiving)
[2014-06-07 06:44:47,561] INFO - ernalArtifactsProcessingLogger - Done: Pre-processing artifacts if needed (archiving)
[2014-06-07 06:44:47,561] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CleanBuildTempDirectoryStage
[2014-06-07 06:44:47,565] INFO - s.CleanBuildTempDirectoryStage - Clearing temporary directory: C:\BuildAgent\temp\buildTmp
[2014-06-07 06:44:47,569] INFO - ernalArtifactsProcessingLogger - Start: Publishing files using WebPublisher
[2014-06-07 06:44:47,572] INFO - ernalArtifactsProcessingLogger - Start: Publishing files using ArtifactsCachePublisher
[2014-06-07 06:44:47,573] INFO - rectories.DirectoryCleanerImpl - Move directory C:\BuildAgent\temp\buildTmp to C:\BuildAgent\temp\.old\buildTmp_1 for cleaning
[2014-06-07 06:44:47,573] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateBuildTempDirectoryStage
[2014-06-07 06:44:47,574] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CreateCheckoutDirectoryStage
[2014-06-07 06:44:47,575] INFO - ace.DirectoryCleanerForceClean - Free disk space under directory C:\BuildAgent\system is 46.67 GB, required 3 GB.
[2014-06-07 06:44:47,575] INFO - ace.DirectoryCleanerForceClean - Free disk space under directory D:\BuildAgent\work\developDailyCppUnitTest is 173.23 GB, required 3 GB.
[2014-06-07 06:44:47,575] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.CleanGeneratedFilesStage
[2014-06-07 06:44:47,576] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.LogCheckoutDirectoryStage
[2014-06-07 06:44:47,576] INFO - jetbrains.buildServer.AGENT - Checkout directory: D:\BuildAgent\work\developDailyCppUnitTest. Exists: true
[2014-06-07 06:44:47,576] INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.patch.UpdateSourcesFromServer
[2014-06-07 06:44:47,576] INFO - ch.UpdateSourcesBuildStageBase - Updating sources: server side checkout
[2014-06-07 06:44:47,576] INFO - .patch.UpdateSourcesFromServer - Requesting patch from server, full checkout - true
[2014-06-07 06:44:47,576] INFO - .patch.UpdateSourcesFromServer - Downloading patch to temp file...
[2014-06-07 06:44:47,576] INFO - .patch.UpdateSourcesFromServer -
Checking folders....
[2014-06-07 06:44:47,576] INFO - .patch.UpdateSourcesFromServer - Checkout directory: 'D:\BuildAgent\work\developDailyCppUnitTest'. Exists: true
[2014-06-07 06:44:47,576] INFO - .patch.UpdateSourcesFromServer - Checkout directory exists. Skipping pre-test
[2014-06-07 06:44:47,577] INFO - jetbrains.buildServer.AGENT - No revision information for developDailyCppUnitTest.xml on agent
[2014-06-07 06:44:47,596] INFO - ernalArtifactsProcessingLogger - Done publishing artifacts to '.teamcity/properties', using 'WebPublisher', total files published: 1
[2014-06-07 06:44:47,596] INFO - ernalArtifactsProcessingLogger - Done publishing artifacts to '.teamcity/properties', using 'ArtifactsCachePublisher', total files published: 1
[2014-06-07 06:44:47,596] INFO - ernalArtifactsProcessingLogger - Done: Publishing files
[2014-06-07 06:44:47,600] INFO - ernalArtifactsProcessingLogger - Publishing artifacts process finished
[2014-06-07 06:45:13,689] INFO - gent.impl.patch.PatchTempFiles - Patch downloaded
[2014-06-07 06:45:13,689] INFO - impl.patch.PatchDownloaderImpl - Checking the patch is correct...
[2014-06-07 06:45:13,693] INFO - impl.patch.PatchDownloaderImpl - Patch checking finished
[2014-06-07 06:45:13,693] INFO - jetbrains.buildServer.AGENT - Patch downloaded for build with id 73105
[2014-06-07 06:45:13,731] INFO - jetbrains.buildServer.AGENT - Attempting to mark checkoutdir developDailyCppUnitTest for build 73105 dirty
[2014-06-07 06:45:13,731] INFO - jetbrains.buildServer.AGENT - Number of vcsRootEntries: [VcsRootEntry[VcsSettings["ScanSoftware" {internal id=53, properties: [externals-mode=externals-full; labelingMessage=Labeled automatically by TeamCity; labelingPatterns=trunk=>tags; secure:svn-password=*****; svn-config-directory=C:\Windows\system32\config\systemprofile\AppData\Roaming\Subversion; svn-use-default-config-directory=true; teamcity:vcsRootName=ScanSoftware; url=*****; user=*****; vcs=svn; working-copy-format=1.8; ]}; Checkout rules: +:1_Sources\ScanSoftware\Testsupport]]]
[2014-06-07 06:45:13,732] INFO - jetbrains.buildServer.AGENT - Recording vcs state. C: 38004_2014/06/04 10:40:46 +0200, Id: 1_svn_2373396656266921473_-1859361061, CR: 1_Sources/ScanSoftware/Testsupport=>1_Sources/ScanSoftware/Testsupport
[2014-06-07 06:45:13,732] INFO - jetbrains.buildServer.AGENT - Moved configuration file developDailyCppUnitTest.xml to old
[2014-06-07 06:45:13,732] INFO - jetbrains.buildServer.AGENT - Stored new configuration file developDailyCppUnitTest.xml
[2014-06-07 06:45:13,732] INFO - .patch.UpdateSourcesFromServer - Applying patch to checkout directory...
[2014-06-07 06:45:13,733] ERROR - .patches.FSPatcherCallbackImpl - Add directory failed. Dir created: false
Child dirs: [.old, 108d35aafa48a6e7, 800be6fe22d17549, cf6ea03feacc5b72, d5a63b6d197b606e, developDaily, developDailyCppUnitTest, developDailyReleaseAsset, developDaily_Test_NUnit_UI, developNightlyDebug_32bit, developNightlyReleaseAsset, developNightlyRunJavaGuiTests, developNightlyJavaGuiTests, developNightly_Test_NUnit_UI, directory.map, e688a90c0dfcd390, f180e3b4dbb31335, faf10ef27d2e3022, Python, 5.3Debug_32bit, 5.3Debug_64bit, 5.3ReleaseAsset, 5.3ReportJavaGuiTests, 5.3RunJavaGuiTests, 5.3, 5.3ReleaseAsset]
[2014-06-07 06:45:13,752] WARN - ch.UpdateSourcesBuildStageBase - Exception occurred while patch applying: Failed to create directory: D:\BuildAgent\work\developDailyCppUnitTest
jetbrains.buildServer.vcs.patches.PatchException: Failed to create directory: D:\BuildAgent\work\developDailyCppUnitTest
at jetbrains.buildServer.vcs.patches.StrictPatcherErrorHandler.error(StrictPatcherErrorHandler.java:24)
at jetbrains.buildServer.vcs.patches.PatcherErrorHandlerBase.error(PatcherErrorHandlerBase.java:63)
at jetbrains.buildServer.vcs.patches.PatcherErrorHandlerBase.addDirectoryFailed(PatcherErrorHandlerBase.java:19)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.addDirectory(FSPatcherCallbackImpl.java:57)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.ensureParentFolder(FSPatcherCallbackImpl.java:154)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.addDirectory(FSPatcherCallbackImpl.java:31)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.ensureParentFolder(FSPatcherCallbackImpl.java:154)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.addDirectory(FSPatcherCallbackImpl.java:31)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.ensureParentFolder(FSPatcherCallbackImpl.java:154)
at jetbrains.buildServer.vcs.patches.FSPatcherCallbackImpl.addDirectory(FSPatcherCallbackImpl.java:31)
at jetbrains.buildServer.vcs.patches.AbstractFSPatcher$Bridge.addDirectory(AbstractFSPatcher.java:78)
at jetbrains.buildServer.vcs.patches.AbstractPatcher$1.addDirectory(AbstractPatcher.java:60)
at jetbrains.buildServer.vcs.patches.AbstractPatcher$1.addDirectory(AbstractPatcher.java:42)
at jetbrains.buildServer.vcs.patches.LowLevelPatcher.readPatchStream(LowLevelPatcher.java:103)
at jetbrains.buildServer.vcs.patches.LowLevelPatcher.applyPatch(LowLevelPatcher.java:88)
at jetbrains.buildServer.vcs.patches.AbstractPatcher.applyPatch(AbstractPatcher.java:42)
at jetbrains.buildServer.vcs.patches.AbstractFSPatcher.applyPatch(AbstractFSPatcher.java:33)
at jetbrains.buildServer.agent.impl.patch.PatchApplierImpl.applyPatch(PatchApplierImpl.java:18)
at jetbrains.buildServer.agent.impl.patch.UpdateSourcesPatcherBase.applyPatch(UpdateSourcesPatcherBase.java:75)
at jetbrains.buildServer.agent.impl.patch.UpdateSourcesFromServer.applyPatchToDisc(UpdateSourcesFromServer.java:101)
at jetbrains.buildServer.agent.impl.patch.UpdateSourcesFromServer.updateSources(UpdateSourcesFromServer.java:87)
at jetbrains.buildServer.agent.impl.patch.UpdateSourcesBuildStageBase.doSourceUpdate(UpdateSourcesBuildStageBase.java:91)
at jetbrains.buildServer.agent.impl.patch.UpdateSourcesBuildStageBase.doRecoverableStage(UpdateSourcesBuildStageBase.java:59)
at jetbrains.buildServer.agent.impl.buildStages.startStages.RecoverableBuildStage.doBuildStage(RecoverableBuildStage.java:74)
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:78)
at jetbrains.buildServer.agent.impl.buildStages.StagesExecutor.doStages(StagesExecutor.java:37)
at jetbrains.buildServer.agent.impl.buildStages.BuildStagesExecutor.doStages(BuildStagesExecutor.java:24)
at jetbrains.buildServer.agent.impl.BuildRunAction.doStages(BuildRunAction.java:70)
at jetbrains.buildServer.agent.impl.BuildRunAction.runBuild(BuildRunAction.java:50)
at jetbrains.buildServer.agent.impl.BuildAgentImpl.doActualBuild(BuildAgentImpl.java:265)
at jetbrains.buildServer.agent.impl.BuildAgentImpl.access$100(BuildAgentImpl.java:52)
at jetbrains.buildServer.agent.impl.BuildAgentImpl$1.run(BuildAgentImpl.java:231)
at java.lang.Thread.run(Thread.java:745)
Also do you know why the log says: "[2014-06-07 06:45:13,733] ERROR - .patches.FSPatcherCallbackImpl - Add directory failed. Dir created: false", while the directory is actually listed in the child dirs list printed directly after that entry?
What if this is not a directory, but a file for some reason? I updated logging and fixes at ftp://ftp.intellij.net/pub/.teamcity/addDirectoryLogged/buildAgent.zip.