Gradle plugin INIT script performance issues.

Hello,

We are currently having an issue with the gradle plugin. For some reason when the plugin's init script is run it will get to a point where it appears to just sit and wait for 11-12 minutes before starting our init script so that our builds can commence. The other strange thing is that it prints out a blank line right after it waits. I've attached the full debug log to this discussion for review, but I'll highlight the relevant lines below. Any help as to what is going on and what we can do to fix it would be most appreciated. We are currently using TC7.0.4.


[14:49:29]: 14:49:29.952 [DEBUG] [org.gradle.cache.internal.DefaultFileLockManager] Releasing lock on no_initscript class cache for initialization script 'C:\BuildAgent\work\349f20642bbb1ab2\modules\init.gradle' (C:\BuildAgent\temp\buildTmp\gradleCache\caches\1.1\scripts\init_4nl9bm39fpfuqpi74ldlch3l82\InitScript\no_initscript).
[14:49:29]: 14:49:29.952 [DEBUG] [org.gradle.cache.internal.DefaultFileLockManager] Waiting to acquire shared lock on no_initscript class cache for initialization script 'C:\BuildAgent\work\349f20642bbb1ab2\modules\init.gradle' (C:\BuildAgent\temp\buildTmp\gradleCache\caches\1.1\scripts\init_4nl9bm39fpfuqpi74ldlch3l82\InitScript\no_initscript).
[14:49:29]: 14:49:29.952 [DEBUG] [org.gradle.cache.internal.DefaultFileLockManager] Lock acquired.
[14:58:18]: 14:58:18.448 [QUIET] [system.out]



Attachment(s):
Main_Unit_Tests_TrendGraph_Javascript_tests_143.log.zip
14 comments
Comment actions Permalink

Alexander,

Could you please try to execute following command in directory: C:\BuildAgent\work\349f20642bbb1ab2 on the build agent

C:\BuildAgent\work\349f20642bbb1ab2\gradlew.bat  --init-script modules/init.gradle --project-dir modules -C rebuild -g C:\BuildAgent\temp\buildTmp\gradleCache -Pworking=webctrl:webctrl -d -s :trendgraph:jstest

and see if Gradle executes build in appropriate time

0
Comment actions Permalink

Nikita,

Thank you for your reply.

I'm trying this now.

EDIT: Running the command manually on the agent has the exact same outcome.

0
Comment actions Permalink

If you reproduced the issue, than it looks like there is some underlying problem with gradle itself.  Do you face same issue on developers workstation? What version of gradle is used? Why do you force recompile of init-script?

0
Comment actions Permalink

We don't use the gradle wrapper to build on developer workstations because we use a custom batch file, no issues there. We are currently using gradle 1.1. We have been forcing rebuild of all gradle scripts due to consistency issues with the gradle caches. I removed that option from the command on the build configuration and it still waited 10-12 minutes. However when I run the same command manually on the agent it does not wait now. That is very curious.

0
Comment actions Permalink

Alexander,


What user account is used to start Teamcity agent? Did you use the same account to enter command manually?

0
Comment actions Permalink

Yes this happens under the same account that is used to launch the build and run the agent. We've also noticed without the -c rebuild that the init script still gets recompiled. I've attached the latest log file.



Attachment(s):
Main_Unit_Tests_TrendGraph_Javascript_tests_186.log.zip
0
Comment actions Permalink

I'd like to bump this issue since we recently upgraded to TeamCity 7.1.4 and the wait time once the init script is run and the build starts running has increased to 20 minutes on a pretty reliable basis.

0
Comment actions Permalink

Alexander,



I am still not sure about the underlying problem.

Could you please try remove your init script (modules/init. gradle) and see if the problem still exists?
Also, can you try to install attached Gradle runner plugin build. See here for instructions: http://confluence.jetbrains.com/display/TCD7/Installing+Additional+Plugins



Attachment(s):
gradle-runner.zip
0
Comment actions Permalink

Nikita

Sorry it has taken me so long to get back with you, we ended up putting this issue on the back burner for some time. We cannot remove our init script as our build would not function without it.

I attempted to install the gradle-runner plugin you sent me however it was broken and did not show anything in the UI.

Alex

0
Comment actions Permalink

Hello Alexander.

Do you still use the same Teamcity (7.1.4) and Gradle (1.1) versions

Please, add following line to the end of gradle-runner\scripts\init.gradle file on TeamCity agent:

logger.debug("TeamCity init script finished")

adding similar debug to your project's modules/init.gradle script would also help.

After that, please run a build with -d (--debug) option set and attach resulting log here.

0
Comment actions Permalink

Nikita sorry it has taken so long for the reply. I was having trouble with the forrum and replying slipped my mind.

We are still using those versions. I went ahead and added a logger to notify when the init script starts as well as stops, I also did the same thing for our init script. The wait is in our init script, but I also attached the log from a local run without teamcity involved, on this one you can see no wait was present.



Attachment(s):
Main_Unit_Tests_TrendGraph_Javascript_tests_1392.log.zip
0
Comment actions Permalink

Alexander, thank you for the logs.

Further troubleshooting will require you to track down hanging opertation in your init.gradle script (e.g., by adding finer grained logging).

Or you can send the init script to me for static investigation, but nailing down the problem without full source tree will be much less productive. If init script contains sensitive information, please send it to teamcity-feedback@jetbrains.com, refer to this thread in subject.

0
Comment actions Permalink

Nikita,

This took an extremely long time to track down. However what I found what was causing this behavior when I started watching processes on the agent machine. We found that for some reason the system process would lock the fileHashes.bin file that gradle generates during startup and cause java to block for an extended period of time.

Further digging into our init script, we discovered that this probably an issue with network/machine speed and using the gradle copy TASK during init. We changed this particular setup to use the copy function and ignore the file stats  and this has given us a work around for this issue.

Thanks for all your help.

Alex

0
Comment actions Permalink

Hello Alexander,

I'm glad to hear your issue got resolved! And thank you very much for getting back to this thread and posting the resolution.

0

Please sign in to leave a comment.