Artifact resolving fails even though artifact exists

I am getting an interesting error in one of my configurations.  This configuration is based on a template, there are many configurations based on the same template that do not exhibit this behaviour.  The config fails with the following error message:

[02:00:07]: Checking for changes
[02:00:15]: Clean build enabled: removing old files from C:\BuildAgent\work\a542fa3fe4df875c
[02:00:15]: Clearing temporary directory: C:\BuildAgent\temp\buildTmp
[02:00:15]: Checkout directory: C:\BuildAgent\work\a542fa3fe4df875c
[02:00:15]: Updating sources: agent side checkout... (3m:33s)
[02:00:15]: [Updating sources: agent side checkout...] Will perform clean checkout. Reason: Checkout directory is empty or doesn't exist
...
[02:03:49]: Resolving artifact dependencies
[02:03:49]: [Resolving artifact dependencies] Failed to resolve artifact dependency <x (build with id: 82033)>: No files matched for pattern "y.pdf" from <x (build with id: 82033)> (jetbrains.buildServer.artifacts.ResolvingFailedException)
...
[02:03:49]: [Resolving artifact dependencies] Failed to resolve 15 of 15 artifact dependencies
[02:03:49]: Artifacts resolving failed. Failed to resolve 15 of 15 artifact dependencies
[02:03:50]: Publishing internal artifacts (29m:20s)
[02:33:09]: [Publishing internal artifacts] Sending build.finish.properties.gz file
[02:03:50]: Build failed to start. Artifacts will not be published for this build
[02:33:16]: Build finished


The error line above is repeated many times, I've removed the other lines and replaced the configuration name with x and artifact filename with y.  Going to the x configuration at build id 82033 shows that y.pdf does exist.  This seems like a bug in TeamCity?  The odd thing is it doesn't seem to occur if I run the build manually but does occur when it runs off its trigger which is set daily to 02:00am.  Also if I run the check dependencies it succeeds.  Any ideas?

I am using TeamCity Enterprise 6.5.5 (build 18087).

Cheers,
Andrew
12 comments
Comment actions Permalink

Andrew,

Could you please set agent logs to DEBUG (instructions here), reproduce the issue and attach resulting logs here?
We may also need to see the artifact dependencies page screenshot.

0
Comment actions Permalink

Hi Nikita,

I am attempting to reproduce and get the logs, unfortunately the bug didn't occur last night.

Cheers,
Andrew

0
Comment actions Permalink

The bug has starting occuring again so I have enabled Debuging in the agent, hopefully I'll capture the relevant information tonight.  In my agent config xml I have two points to enable debugging:

  <category name="jetbrains.buildServer">
    <!--DELETE THIS LINE FOR ENABLING DEBUG LOGGING--> <!--
    <priority value="DEBUG"/>
--> <!--DELETE THIS LINE FOR ENABLING DEBUG LOGGING-->
    <appender-ref ref="ROLL"/>
  </category>

  <category name="teamcity.out">
    <appender-ref ref="ROLL.BUILD"/>
  </category>

  <category name="teamcity.err">
    <appender-ref ref="ROLL.BUILD"/>
  </category>

  <category name="jetbrains.buildServer.XMLRPC">
    <!--<priority value="DEBUG"/>-->
    <appender-ref ref="ROLL.XMLRPC"/>
  </category>

  <category name="javasvn.output">
    <!--<priority value="DEBUG"/>-->
    <appender-ref ref="SVN.LOG"/>
  </category>



I wasn't sure if you needed both the jetbrains.buildserver.xmlrpc and jetbrains.buidlserver debugging info so I just enabled both of them.

Here is a screenshot of the artifact dependencies, there are no snapshot dependencies:
InstallerBuildDependencies.PNG

Cheers,
Andrew

0
Comment actions Permalink

Thank you, Andrew, I'll be waiting for debug information.

0
Comment actions Permalink

In the teamcity-agent.log, for the build that failed I found the following:

[2013-01-15 02:02:54,180]   INFO - l.patch.UpdateSourcesFromAgent - Agent sources updated successfully
[2013-01-15 02:02:54,180]   INFO - ch.UpdateSourcesBuildStageBase - Sources updated for 2m:35s
[2013-01-15 02:02:54,180]  DEBUG - r.agent.impl.AgentLogProxyImpl - Put 1 log messages to queue:83346
[2013-01-15 02:02:54,180]   INFO - ace.DirectoryCleanerForceClean - Free disk space under directory C:\BuildAgent\work\a542fa3fe4df875c is 4.0Gb, required 3.0Gb.
[2013-01-15 02:02:54,180]   INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.AppendBuildParametersFromFileStage
[2013-01-15 02:02:54,180]   INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.ReplaceReferencesInAtrifactDependenciesStage
[2013-01-15 02:02:54,180]   INFO - uildStages.BuildStagesExecutor - Call stage jetbrains.buildServer.agent.impl.buildStages.startStages.DownloadDependenciesStage
[2013-01-15 02:02:54,242]   INFO -    jetbrains.buildServer.AGENT - Resolving artifact dependencies...
[2013-01-15 02:02:54,242]  DEBUG - r.artifacts.impl.HttpDiskCache - Http cache miss: new entry [http://TeamCityServer:8082/httpAuth/repository/download/bt81/83156.tcbuildid/teamcity-ivy.xml]
[2013-01-15 02:02:54,258]  DEBUG - r.artifacts.impl.HttpDiskCache - Http disk cache - content fetched from [http://TeamCityServer:8082/httpAuth/repository/download/bt81/83156.tcbuildid/teamcity-ivy.xml]
[2013-01-15 02:02:54,321]  ERROR -    jetbrains.buildServer.AGENT - Failed to resolve artifact dependency <ProjectX :: ConfigY (build with id: 83156)>: No files matched for pattern "Z.pdf" from <ProjectX :: ConfigY (build with id: 83156)> (jetbrains.buildServer.artifacts.ResolvingFailedException)
[2013-01-15 02:02:54,336]  DEBUG -    jetbrains.buildServer.AGENT - Failed to resolve artifact dependency <ProjectX :: ConfigY (build with id: 83156)>: No files matched for pattern "Z.pdf" from <ProjectX :: ConfigY (build with id: 83156)> (jetbrains.buildServer.artifacts.ResolvingFailedException)
jetbrains.buildServer.artifacts.ResolvingFailedException: No files matched for pattern "Z.pdf" from <ProjectX :: ConfigY (build with id: 83156)>
     at jetbrains.buildServer.artifacts.impl.PlainDependencyResolver.resolveDependency(PlainDependencyResolver.java:104)
     at jetbrains.buildServer.artifacts.impl.PlainDependencyResolver.resolve(PlainDependencyResolver.java:58)
     at jetbrains.buildServer.agent.impl.AlteringDependencyResolverAgent.resolve(AlteringDependencyResolverAgent.java:42)
     at jetbrains.buildServer.agent.impl.buildStages.startStages.DownloadDependenciesStage.doStage(DownloadDependenciesStage.java:70)
     at jetbrains.buildServer.agent.impl.buildStages.startStages.DownloadDependenciesStage.doRecoverableStage(DownloadDependenciesStage.java:41)
     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:29)
     at jetbrains.buildServer.agent.impl.buildStages.StagesExecutor.callRunStage(StagesExecutor.java:76)
     at jetbrains.buildServer.agent.impl.buildStages.StagesExecutor.doStages(StagesExecutor.java:36)
     at jetbrains.buildServer.agent.impl.buildStages.BuildStagesExecutor.doStages(BuildStagesExecutor.java:24)
     at jetbrains.buildServer.agent.impl.BuildRunAction.doStages(BuildRunAction.java:65)
     at jetbrains.buildServer.agent.impl.BuildRunAction.runBuild(BuildRunAction.java:52)
     at jetbrains.buildServer.agent.impl.BuildAgentImpl.doActualBuild(BuildAgentImpl.java:245)
     at jetbrains.buildServer.agent.impl.BuildAgentImpl.access$100(BuildAgentImpl.java:50)
     at jetbrains.buildServer.agent.impl.BuildAgentImpl$1.run(BuildAgentImpl.java:218)
     at java.lang.Thread.run(Unknown Source)
[2013-01-15 02:02:54,336]  DEBUG - r.artifacts.impl.HttpDiskCache - Http cache miss: new entry [http://TeamCityServer:8082/httpAuth/repository/download/bt82/83157.tcbuildid/teamcity-ivy.xml]
[2013-01-15 02:02:54,352]  DEBUG - r.artifacts.impl.HttpDiskCache - Http disk cache - content fetched from [http://TeamCityServer:8082/httpAuth/repository/download/bt82/83157.tcbuildid/teamcity-ivy.xml]
[2013-01-15 02:02:54,352]  ERROR -    jetbrains.buildServer.AGENT - Failed to resolve artifact dependency <AProjectX:: ConfigY (build with id: 83157)>: No files matched for pattern "Z.pdf" from <ProjectX :: ConfigY (build with id: 83157)> (jetbrains.buildServer.artifacts.ResolvingFailedException)
[2013-01-15 02:02:54,352]  DEBUG -    jetbrains.buildServer.AGENT - Failed to resolve artifact dependency <ProjectX :: ConfigY (build with id: 83157)>: No files matched for pattern "Z.pdf" from <ProjectX :: ConfigY (build with id: 83157)> (jetbrains.buildServer.artifacts.ResolvingFailedException)
jetbrains.buildServer.artifacts.ResolvingFailedException: No files matched for pattern "Z.pdf" from <ProjectX :: ConfigY (build with id: 83157)>
     at jetbrains.buildServer.artifacts.impl.PlainDependencyResolver.resolveDependency(PlainDependencyResolver.java:104)
     at jetbrains.buildServer.artifacts.impl.PlainDependencyResolver.resolve(PlainDependencyResolver.java:58)
     at jetbrains.buildServer.agent.impl.AlteringDependencyResolverAgent.resolve(AlteringDependencyResolverAgent.java:42)
     at jetbrains.buildServer.agent.impl.buildStages.startStages.DownloadDependenciesStage.doStage(DownloadDependenciesStage.java:70)
     at jetbrains.buildServer.agent.impl.buildStages.startStages.DownloadDependenciesStage.doRecoverableStage(DownloadDependenciesStage.java:41)
     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:29)
     at jetbrains.buildServer.agent.impl.buildStages.StagesExecutor.callRunStage(StagesExecutor.java:76)
     at jetbrains.buildServer.agent.impl.buildStages.StagesExecutor.doStages(StagesExecutor.java:36)
     at jetbrains.buildServer.agent.impl.buildStages.BuildStagesExecutor.doStages(BuildStagesExecutor.java:24)
     at jetbrains.buildServer.agent.impl.BuildRunAction.doStages(BuildRunAction.java:65)
     at jetbrains.buildServer.agent.impl.BuildRunAction.runBuild(BuildRunAction.java:52)
     at jetbrains.buildServer.agent.impl.BuildAgentImpl.doActualBuild(BuildAgentImpl.java:245)
     at jetbrains.buildServer.agent.impl.BuildAgentImpl.access$100(BuildAgentImpl.java:50)
     at jetbrains.buildServer.agent.impl.BuildAgentImpl$1.run(BuildAgentImpl.java:218)
     at java.lang.Thread.run(Unknown Source)


After many of the above message:

[2013-01-15 02:02:54,555]  ERROR -    jetbrains.buildServer.AGENT - Failed to resolve 14 of 14 artifact dependencies
jetbrains.buildServer.artifacts.ResolvingFailedException: Failed to resolve 14 of 14 artifact dependencies
     at jetbrains.buildServer.artifacts.impl.PlainDependencyResolver.resolve(PlainDependencyResolver.java:72)
     at jetbrains.buildServer.agent.impl.AlteringDependencyResolverAgent.resolve(AlteringDependencyResolverAgent.java:42)
     at jetbrains.buildServer.agent.impl.buildStages.startStages.DownloadDependenciesStage.doStage(DownloadDependenciesStage.java:70)
     at jetbrains.buildServer.agent.impl.buildStages.startStages.DownloadDependenciesStage.doRecoverableStage(DownloadDependenciesStage.java:41)
     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:29)
     at jetbrains.buildServer.agent.impl.buildStages.StagesExecutor.callRunStage(StagesExecutor.java:76)
     at jetbrains.buildServer.agent.impl.buildStages.StagesExecutor.doStages(StagesExecutor.java:36)
     at jetbrains.buildServer.agent.impl.buildStages.BuildStagesExecutor.doStages(BuildStagesExecutor.java:24)
     at jetbrains.buildServer.agent.impl.BuildRunAction.doStages(BuildRunAction.java:65)
     at jetbrains.buildServer.agent.impl.BuildRunAction.runBuild(BuildRunAction.java:52)
     at jetbrains.buildServer.agent.impl.BuildAgentImpl.doActualBuild(BuildAgentImpl.java:245)
     at jetbrains.buildServer.agent.impl.BuildAgentImpl.access$100(BuildAgentImpl.java:50)
     at jetbrains.buildServer.agent.impl.BuildAgentImpl$1.run(BuildAgentImpl.java:218)
     at java.lang.Thread.run(Unknown Source)
[2013-01-15 02:02:54,571]   INFO -    jetbrains.buildServer.AGENT - Finished resolving artifacts
[2013-01-15 02:02:54,571]   WARN - nt.impl.BuildExceptionsHandler - Failed to execute build stage: DownloadDependenciesStage. Artifacts resolving failed. Failed to resolve 14 of 14 artifact dependencies
jetbrains.buildServer.agent.impl.buildStages.BuildStageExecutionException: Artifacts resolving failed. Failed to resolve 14 of 14 artifact dependencies
     at jetbrains.buildServer.agent.impl.buildStages.BuildStagesExecutor$1.callStage(BuildStagesExecutor.java:33)
     at jetbrains.buildServer.agent.impl.buildStages.BuildStagesExecutor$1.callStage(BuildStagesExecutor.java:29)
     at jetbrains.buildServer.agent.impl.buildStages.StagesExecutor.callRunStage(StagesExecutor.java:76)
     at jetbrains.buildServer.agent.impl.buildStages.StagesExecutor.doStages(StagesExecutor.java:36)
     at jetbrains.buildServer.agent.impl.buildStages.BuildStagesExecutor.doStages(BuildStagesExecutor.java:24)
     at jetbrains.buildServer.agent.impl.BuildRunAction.doStages(BuildRunAction.java:65)
     at jetbrains.buildServer.agent.impl.BuildRunAction.runBuild(BuildRunAction.java:52)
     at jetbrains.buildServer.agent.impl.BuildAgentImpl.doActualBuild(BuildAgentImpl.java:245)
     at jetbrains.buildServer.agent.impl.BuildAgentImpl.access$100(BuildAgentImpl.java:50)
     at jetbrains.buildServer.agent.impl.BuildAgentImpl$1.run(BuildAgentImpl.java:218)
     at java.lang.Thread.run(Unknown Source)
Caused by: jetbrains.buildServer.RunBuildException: Artifacts resolving failed. Failed to resolve 14 of 14 artifact dependencies
     at jetbrains.buildServer.agent.impl.buildStages.startStages.DownloadDependenciesStage.doStage(DownloadDependenciesStage.java:86)
     at jetbrains.buildServer.agent.impl.buildStages.startStages.DownloadDependenciesStage.doRecoverableStage(DownloadDependenciesStage.java:41)
     at jetbrains.buildServer.agent.impl.buildStages.startStages.RecoverableBuildStage.doBuildStage(RecoverableBuildStage.java:74)
     at jetbrains.buildServer.agent.impl.buildStages.BuildStagesExecutor$1.callStage(BuildStagesExecutor.java:31)
     ... 10 more
[2013-01-15 02:02:54,586]  DEBUG - r.agent.impl.AgentLogProxyImpl - Flush messages for explicit request from Build id=83346
[2013-01-15 02:02:54,586]  DEBUG - r.agent.impl.AgentLogProxyImpl - Later executor invocation for 3 remote commands, requestor: explicit request from Build id=83346
[2013-01-15 02:02:54,586]  DEBUG -   jetbrains.buildServer.XMLRPC - >>> XML-RPC request >>>
[2013-01-15 02:02:54,586]  DEBUG -   jetbrains.buildServer.XMLRPC - <?xml version="1.0"?><methodCall><methodName>buildServer.log</methodName><params><param><value><![CDATA[83346]]></value></param><param><value><array><data><value><![CDATA[<?xml version="1.0" encoding="UTF-8" ?>
<jetbrains.buildServer.messages.BuildMessage1><mySourceId>DefaultMessage</mySourceId><myTimestamp>1358215373149</myTimestamp><myStatus>1</myStatus><myTypeId>BlockEnd</myTypeId><myFlowId></myFlowId><myValue ><blockName>VCS Root: Alaska Trunk</blockName><blockType>checkout</blockType></myValue></jetbrains.buildServer.messages.BuildMessage1>]]></value><value><![CDATA[<?xml version="1.0" encoding="UTF-8" ?>
<jetbrains.buildServer.messages.BuildMessage1><mySourceId>DefaultMessage</mySourceId><myTimestamp>1358215373149</myTimestamp><myStatus>1</myStatus><myTypeId>BlockStart</myTypeId><myFlowId></myFlowId><myValue ><blockName>VCS Root: SigningBranchCambridge</blockName><blockType>checkout</blockType></myValue></jetbrains.buildServer.messages.BuildMessage1>]]></value><value><![CDATA[<?xml version="1.0" encoding="UTF-8" ?>
<jetbrains.buildServer.messages.BuildMessage1><mySourceId>DefaultMessage</mySourceId><myTimestamp>1358215373149</myTimestamp><myStatus>1</myStatus><myTypeId>Text</myTypeId><myFlowId></myFlowId><myValue >checkout rules: client-binaries=&gt;tools/signing-services; revision: 66424_2012/11/27 03:04:02 +0000</myValue></jetbrains.buildServer.messages.BuildMessage1>]]></value><value><![CDATA[<?xml version="1.0" encoding="UTF-8" ?>
<jetbrains.buildServer.messages.BuildMessage1><mySourceId>DefaultMessage</mySourceId><myTimestamp>1358215373149</myTimestamp><myStatus>1</myStatus><myTypeId>Text</myTypeId><myFlowId></myFlowId><myValue >Will use fast SVN update</myValue></jetbrains.buildServer.messages.BuildMessage1>]]></value><value><![CDATA[<?xml version="1.0" encoding="UTF-8" ?>
<jetbrains.buildServer.messages.BuildMessage1><mySourceId>DefaultMessage</mySourceId><myTimestamp>1358215374180</myTimestamp><myStatus>1</myStatus><myTypeId>BlockEnd</myTypeId><myFlowId></myFlowId><myValue ><blockName>VCS Root: SigningBranchCambridge</blockName><blockType>checkout</blockType></myValue></jetbrains.buildServer.messages.BuildMessage1>]]></value></data></array></value></param></params></methodCall>
[2013-01-15 02:02:54,586]  DEBUG -   jetbrains.buildServer.XMLRPC - <<< XML-RPC response <<<
[2013-01-15 02:02:54,586]  DEBUG -   jetbrains.buildServer.XMLRPC - <?xml version="1.0"?><methodResponse><fault><value><struct><member><name>faultString</name><value>jetbrains.buildServer.ServerCleanupInProgressException: Server is maintaining its database at the moment. It may take from several minutes to several hours depending on the size of the database.</value></member><member><name>faultCode</name><value><int>0</int></value></member></struct></value></fault></methodResponse>
[2013-01-15 02:02:54,586]  DEBUG - r.agent.impl.AgentLogProxyImpl - Send 5 log messages FAIL
[2013-01-15 02:02:54,586]  DEBUG - r.agent.impl.AgentLogProxyImpl - Failed to perform remote command 5 log messages for build 83346. Call http://TeamCityServer:8082/RPC2 buildServer.log: org.apache.xmlrpc.XmlRpcException: jetbrains.buildServer.ServerCleanupInProgressException: Server is maintaining its database at the moment. It may take from several minutes to several hours depending on the size of the database.
jetbrains.buildServer.xmlrpc.RemoteCallException: Call http://TeamCityServer:8082/RPC2 buildServer.log: org.apache.xmlrpc.XmlRpcException: jetbrains.buildServer.ServerCleanupInProgressException: Server is maintaining its database at the moment. It may take from several minutes to several hours depending on the size of the database.
     at jetbrains.buildServer.xmlrpc.AbstractXmlRpcTarget.call(AbstractXmlRpcTarget.java:91)
     at jetbrains.buildServer.agent.impl.XmlRpcAgentLogListener$1.invoke(XmlRpcAgentLogListener.java:55)
     at jetbrains.buildServer.agent.impl.XmlRpcAgentLogListener.doSendRequest(XmlRpcAgentLogListener.java:102)
     at jetbrains.buildServer.agent.impl.XmlRpcAgentLogListener.log(XmlRpcAgentLogListener.java:53)
     at jetbrains.buildServer.agent.impl.ServerXmlRpcProxy.access$001(ServerXmlRpcProxy.java:22)
     at jetbrains.buildServer.agent.impl.ServerXmlRpcProxy$1.run(ServerXmlRpcProxy.java:161)
     at jetbrains.buildServer.agent.impl.ServerXmlRpcProxy.sendXmlRpc(ServerXmlRpcProxy.java:204)
     at jetbrains.buildServer.agent.impl.ServerXmlRpcProxy.log(ServerXmlRpcProxy.java:159)
     at jetbrains.buildServer.agent.impl.AgentLogProxyImpl$LogMessagesRemoteAction.run(AgentLogProxyImpl.java:462)
     at jetbrains.buildServer.agent.impl.AgentLogProxyImpl.sendActionRequest(AgentLogProxyImpl.java:89)
     at jetbrains.buildServer.agent.impl.AgentLogProxyImpl.access$1300(AgentLogProxyImpl.java:29)
     at jetbrains.buildServer.agent.impl.AgentLogProxyImpl$RemoteActionPendingCommand.run(AgentLogProxyImpl.java:428)
     at jetbrains.buildServer.agent.impl.AgentLogProxyImpl$LaterExecutorTask.flushMessages(AgentLogProxyImpl.java:348)
     at jetbrains.buildServer.agent.impl.AgentLogProxyImpl$LaterExecutorTask.run(AgentLogProxyImpl.java:327)
     at jetbrains.buildServer.agent.impl.AgentLogProxyImpl.flush(AgentLogProxyImpl.java:263)
     at jetbrains.buildServer.agent.impl.BuildAgentImpl$AgentServerLoggerFacade.flush(BuildAgentImpl.java:923)
     at jetbrains.buildServer.agent.impl.BuildExceptionHandlerBase.failBuildWithException(BuildExceptionHandlerBase.java:75)
     at jetbrains.buildServer.agent.impl.BuildExceptionHandlerBase.processBasicException(BuildExceptionHandlerBase.java:54)
     at jetbrains.buildServer.agent.impl.BuildExceptionsHandler.handleBuildStageException(BuildExceptionsHandler.java:26)
     at jetbrains.buildServer.agent.impl.BuildRunAction.doStages(BuildRunAction.java:68)
     at jetbrains.buildServer.agent.impl.BuildRunAction.runBuild(BuildRunAction.java:52)
     at jetbrains.buildServer.agent.impl.BuildAgentImpl.doActualBuild(BuildAgentImpl.java:245)
     at jetbrains.buildServer.agent.impl.BuildAgentImpl.access$100(BuildAgentImpl.java:50)
     at jetbrains.buildServer.agent.impl.BuildAgentImpl$1.run(BuildAgentImpl.java:218)
     at java.lang.Thread.run(Unknown Source)
Caused by: org.apache.xmlrpc.XmlRpcException: jetbrains.buildServer.ServerCleanupInProgressException: Server is maintaining its database at the moment. It may take from several minutes to several hours depending on the size of the database.
     at org.apache.xmlrpc.XmlRpcClientResponseProcessor.decodeException(XmlRpcClientResponseProcessor.java:104)
     at org.apache.xmlrpc.XmlRpcClientResponseProcessor.decodeResponse(XmlRpcClientResponseProcessor.java:71)
     at org.apache.xmlrpc.XmlRpcClientWorker.execute(XmlRpcClientWorker.java:73)
     at org.apache.xmlrpc.TCXmlRpcClient$1.execute(TCXmlRpcClient.java:89)
     at org.apache.xmlrpc.XmlRpcClient.execute(XmlRpcClient.java:194)
     at org.apache.xmlrpc.XmlRpcClient.execute(XmlRpcClient.java:185)
     at org.apache.xmlrpc.XmlRpcClient.execute(XmlRpcClient.java:178)
     at jetbrains.buildServer.xmlrpc.impl.CommonsXmlRpcTargetImpl$1.execute(CommonsXmlRpcTargetImpl.java:70)
     at jetbrains.buildServer.xmlrpc.AbstractXmlRpcTarget.call(AbstractXmlRpcTarget.java:81)
     ... 24 more
[2013-01-15 02:02:54,586]   INFO - r.agent.impl.AgentLogProxyImpl - Will try to resend messages later (add PING): Call http://TeamCityServer:8082/RPC2 buildServer.log: org.apache.xmlrpc.XmlRpcException: jetbrains.buildServer.ServerCleanupInProgressException: Server is maintaining its database at the moment. It may take from several minutes to several hours depending on the size of the database.
[2013-01-15 02:02:54,586]  DEBUG - r.agent.impl.AgentLogProxyImpl - Message not delivered: Call http://TeamCityServer:8082/RPC2 buildServer.log: org.apache.xmlrpc.XmlRpcException: jetbrains.buildServer.ServerCleanupInProgressException: Server is maintaining its database at the moment. It may take from several minutes to several hours depending on the size of the database.
jetbrains.buildServer.xmlrpc.RemoteCallException: Call http://TeamCityServer:8082/RPC2 buildServer.log: org.apache.xmlrpc.XmlRpcException: jetbrains.buildServer.ServerCleanupInProgressException: Server is maintaining its database at the moment. It may take from several minutes to several hours depending on the size of the database.
     at jetbrains.buildServer.xmlrpc.AbstractXmlRpcTarget.call(AbstractXmlRpcTarget.java:91)
     at jetbrains.buildServer.agent.impl.XmlRpcAgentLogListener$1.invoke(XmlRpcAgentLogListener.java:55)
     at jetbrains.buildServer.agent.impl.XmlRpcAgentLogListener.doSendRequest(XmlRpcAgentLogListener.java:102)
     at jetbrains.buildServer.agent.impl.XmlRpcAgentLogListener.log(XmlRpcAgentLogListener.java:53)
     at jetbrains.buildServer.agent.impl.ServerXmlRpcProxy.access$001(ServerXmlRpcProxy.java:22)
     at jetbrains.buildServer.agent.impl.ServerXmlRpcProxy$1.run(ServerXmlRpcProxy.java:161)
     at jetbrains.buildServer.agent.impl.ServerXmlRpcProxy.sendXmlRpc(ServerXmlRpcProxy.java:204)
     at jetbrains.buildServer.agent.impl.ServerXmlRpcProxy.log(ServerXmlRpcProxy.java:159)
     at jetbrains.buildServer.agent.impl.AgentLogProxyImpl$LogMessagesRemoteAction.run(AgentLogProxyImpl.java:462)
     at jetbrains.buildServer.agent.impl.AgentLogProxyImpl.sendActionRequest(AgentLogProxyImpl.java:89)
     at jetbrains.buildServer.agent.impl.AgentLogProxyImpl.access$1300(AgentLogProxyImpl.java:29)
     at jetbrains.buildServer.agent.impl.AgentLogProxyImpl$RemoteActionPendingCommand.run(AgentLogProxyImpl.java:428)
     at jetbrains.buildServer.agent.impl.AgentLogProxyImpl$LaterExecutorTask.flushMessages(AgentLogProxyImpl.java:348)
     at jetbrains.buildServer.agent.impl.AgentLogProxyImpl$LaterExecutorTask.run(AgentLogProxyImpl.java:327)
     at jetbrains.buildServer.agent.impl.AgentLogProxyImpl.flush(AgentLogProxyImpl.java:263)
     at jetbrains.buildServer.agent.impl.BuildAgentImpl$AgentServerLoggerFacade.flush(BuildAgentImpl.java:923)
     at jetbrains.buildServer.agent.impl.BuildExceptionHandlerBase.failBuildWithException(BuildExceptionHandlerBase.java:75)
     at jetbrains.buildServer.agent.impl.BuildExceptionHandlerBase.processBasicException(BuildExceptionHandlerBase.java:54)
     at jetbrains.buildServer.agent.impl.BuildExceptionsHandler.handleBuildStageException(BuildExceptionsHandler.java:26)
     at jetbrains.buildServer.agent.impl.BuildRunAction.doStages(BuildRunAction.java:68)
     at jetbrains.buildServer.agent.impl.BuildRunAction.runBuild(BuildRunAction.java:52)
     at jetbrains.buildServer.agent.impl.BuildAgentImpl.doActualBuild(BuildAgentImpl.java:245)
     at jetbrains.buildServer.agent.impl.BuildAgentImpl.access$100(BuildAgentImpl.java:50)
     at jetbrains.buildServer.agent.impl.BuildAgentImpl$1.run(BuildAgentImpl.java:218)
     at java.lang.Thread.run(Unknown Source)



The thing to note is that the buildServer cleanup started at some point in this process.  Note that the artifact cleanup is set to 03h00 in the TeamCity Gui (the next cleanup is due: 16 Jan 13 03:00 (GMT +0000)).

There is a lot more in the log but the whole file is 10mB.  Is that enough information or is there another way I can get the file to you?  I have disabled the cleanup for tonight to see if it is causing this issue.

Cheers,
Andrew

0
Comment actions Permalink

There is no need to send us full log right now, as it looks like the issue is caused by clash with TeamCity maintenance. So just keep the log, until it is confirmed.

Also, could you please try to locate file on the agent machine somewhere on the following path:

buildAgent/system/.artifacts_cache/TeamCityServer_8082/httpAuth/repository/download/bt81/83156.tcbuildid/teamcity-ivy.xml

and compare it with a file you can download from  http://teamcityserver:8082/httpAuth/repository/download/bt81/83156.tcbuildid/teamcity-ivy.xml

Do they differ?

0
Comment actions Permalink

Unfortunately the folder "83156.tcbuildid" on the build agent doesn't exist, there is only one folder in the bt81 folder, namely "83495.tcbuildid".  The downlaoded xml looks like this:

<?xml version="1.0" encoding="UTF-8"?>
<ivy-module version="1.4">
<info organisation="org" module="bt81" revision="83156.tcbuildid"/>

<publications>
<artifact name=".teamcity/properties/build.finish.properties" type="gz" ext="gz"/>

<artifact name=".teamcity/properties/build.start.properties" type="gz" ext="gz"/>

<artifact name="z" type="pdf" ext="pdf"/>

<artifact name="z" type="versions" ext="versions"/>

<artifact name="z" type="xml" ext="xml"/>
</publications>
</ivy-module>



I would think it's possibly that the folder got cleaned up as a lot of our build process use the free space build feature and do free up a lot of space when they run.

Cheers,
Andrew

0
Comment actions Permalink

Andrew, it is normal, that the file got cleaned. What about the one available at http://teamcityserver:8082/httpAuth/repository/download/bt81/83156.tcbuildid/teamcity-ivy.xml ? Does it describe "z.pdf"?

0
Comment actions Permalink

See above post... (altered to show z.pdf, I removed the actual file-name from the orignal log and forgot to change it in the last post)

0
Comment actions Permalink

Do you need any mnore information?  Bear in mind the post above does show the content of http://teamcityserver:8082/httpAuth/repository/download/bt81/83156.tcbuildid/teamcity-ivy.xml.

Cheers,
Andrew

0
Comment actions Permalink

Any further news on this issue, it is still occuring in our build system.

Cheers,
Andrew

0
Comment actions Permalink

Andrew, sorry for not responding for a long time.



As far as I remember, you were going to try to make an experiment: disable cleanup for one night and see if scheduled build at 2 a.m. succeeds. Did you have an opportunity to make this experiment?

0

Please sign in to leave a comment.