Long delay until starting build on agent

Answered

Hi, 

there's a ~ 2-3 minute delay until build is started on agent. There's this message in build log:

"The build is removed from the queue to be prepared for the start"

Then couple minutes later it continues with the build:

"Starting the build on the agent "...""

 

The same same situation happens with all agents, both linux and windows, agents seem to be idle during that period. Any ideas how this can be improved?

0
7 comments

Hi,

Can you post more details of your build log? Generally speaking, there are some tasks that need to happen before the build can start. You should see some information between `The build is removed from the queue to be prepared for the start` and `Starting the build on the agent`, such as `Collecting changes in n VCS roots`. 

Thanks,

Eric

0
0

You can download the full build log from the build results page. There may be some additional information found in that log, but not always. Click on the "Download Full Build Log" link as shown below:

It may also be worth looking in the teamcity-server.log for more information. This can be found at <teamcity home directory>/logs/teamcity-server.log. I have sometimes seen some third-party plugins slow down this process. If you're using any third-party plugins, you could try disabling them to see if there is any effect on build start time.

0

I have a similar problem. Here is an excerpt from my downloaded logs:

[17:26:23]E: bt275 (running for 9m:51s)
[17:26:23]i: TeamCity server version is 10.0.4 (build 42538)
[17:26:23] : Finalize build settings
[17:26:28] : The build is removed from the queue to be prepared for the start
[17:35:55] : Collecting changes in 2 VCS roots (1s)
[17:35:55] :     [Collecting changes in 2 VCS roots] VCS Root details

There is a ~ 10 minutes constant delay before collecting changes starts.

There is a similar delay at the end:

[17:36:00] : Publishing internal artifacts
[17:36:00] :     [Publishing internal artifacts] Publishing 1 file using [WebPublisher]
[17:36:00] :     [Publishing internal artifacts] Publishing 1 file using [ArtifactsCachePublisher]
[17:45:27] : Build finished

I can't find more helpful logs. 

0

Found that the delays are caused by cleaning file system:

[2022-03-02 17:25:13,337]   INFO - dDirectoryBasedCleanupRegistry - Removing files from /data/cloud/TeamCityAgents/agent/temp/.old 
[2022-03-02 17:27:50,616]   INFO - ldServer.AGENT.PollingProtocol - New command is received from server "agentFileManager.requestDirectoryStructureFast" {id = 25} 
[2022-03-02 17:27:52,760]   INFO - ldServer.AGENT.PollingProtocol - New command is received from server "agentFileManager.requestFile" {id = 26} 
[2022-03-02 17:28:06,440]   INFO - ldServer.AGENT.PollingProtocol - New command is received from server "agentFileManager.requestDirectoryStructureFast" {id = 27} 
[2022-03-02 17:28:08,690]   INFO - ldServer.AGENT.PollingProtocol - New command is received from server "agentFileManager.requestFile" {id = 28} 
[2022-03-02 17:28:23,398]   INFO - ldServer.AGENT.PollingProtocol - New command is received from server "agentFileManager.requestDirectoryStructureFast" {id = 29} 
[2022-03-02 17:28:25,503]   INFO - ldServer.AGENT.PollingProtocol - New command is received from server "agentFileManager.requestFile" {id = 30} 
[2022-03-02 17:28:27,413]   INFO - ldServer.AGENT.PollingProtocol - New command is received from server "agentFileManager.requestDirectoryStructureFast" {id = 31} 
[2022-03-02 17:28:36,771]   INFO - ldServer.AGENT.PollingProtocol - New command is received from server "agentFileManager.requestFile" {id = 32} 
[2022-03-02 17:28:45,641]   INFO - ldServer.AGENT.PollingProtocol - New command is received from server "agentFileManager.requestDirectoryStructureFast" {id = 33} 
[2022-03-02 17:30:13,318]   INFO - r.artifacts.impl.HttpDiskCache - Cleaning up items with life time in cache greater than 172800 seconds 

[...]

[2022-03-02 17:30:13,338]   INFO - dDirectoryBasedCleanupRegistry - Removing files from /data/cloud/TeamCityAgents/agent/temp/.old 
[2022-03-02 17:35:13,318]   INFO - r.artifacts.impl.HttpDiskCache - Cleaning up items with life time in cache greater than 172800 seconds 

[...]

[2022-03-02 17:36:02,251]   INFO -    jetbrains.buildServer.AGENT - Updating agent parameters on the server: AgentDetails{Name='builder6.xx.com', [...] 
[2022-03-02 17:41:00,862]   INFO - r.artifacts.impl.HttpDiskCache - Cleaning up items with life time in cache greater than 172800 seconds 

 [...]

[2022-03-02 17:41:00,885]   INFO - dDirectoryBasedCleanupRegistry - Removing files from /data/cloud/TeamCityAgents/agent/temp/.old 
[2022-03-02 17:46:00,862]   INFO - r.artifacts.impl.HttpDiskCache - Cleaning up items with life time in cache greater than 172800 seconds 

 

0

Issue was caused by plugins. Was not trivial to find. Logs were not in the agent's logs, but TeamCity's main logs.

0

Hi Claude

we have the same issue… i wonder ask if you finally resolved your issue…

Thank you!

0

Please sign in to leave a comment.