[GRADLE-2228] Tooling API: Avoid unnecessary daemon processes creation Created: 13/Apr/12  Updated: 04/Jan/13  Resolved: 11/May/12

Status: Resolved
Project: Gradle
Affects Version/s: 1.0-rc-1
Fix Version/s: 1.1-rc-1

Type: Bug
Reporter: Denis Zhdanov Assignee: Szczepan Faber
Resolution: Fixed Votes: 5

Attachments: File daemon-3865.out.log     File daemon-4047.out.log     File daemon-4152.out.log     Text File idea.log     File intellij-gradle-verbose-logs.tar.gz     Zip Archive toolingSandBox.zip    

 Description   

One of the IntelliJ IDEA gradle integration users reported that new gradle daemon process is spawned every time the gradle api is asked to resolve the project (execute org.gradle.tooling.ModelBuilder.get()).

Please define what information should be provided in order to sort the problem out



 Comments   
Comment by Szczepan Faber [ 14/Apr/12 ]

Thanks for reporting. I'm looking at it. I cannot reproduce it on my Mac but linux vm should do.

Comment by Szczepan Faber [ 16/Apr/12 ]

Can you help out diagnosing the problem?

It would be cool if you could provide daemon log files. They live under ~/.gradle/daemon/<version>. I'd totally appreciate if you could lose the existing logs, reproduce the problem and zip+attach the logs to this ticket.

I'm trying to investigate this problem on my end.

Comment by Ryan Stewart [ 16/Apr/12 ]

I've attached the logs. 3865 is from initially starting IntelliJ, which refreshes the project. Then I manually refreshed it twice, which spawned 4047 and 4152.

Comment by Szczepan Faber [ 16/Apr/12 ]

Hmmm, I cannot see from the logs what's wrong. I'll attach a simple gradle project with tooling API sample and kindly ask you to run it and send me the output, would that be ok?

Comment by Szczepan Faber [ 16/Apr/12 ]

If you could unzip the attached zip, run ./gradlew run few times and tell us if the daemons are spawned? Daemon logs not required but if you do see the problem, can you attach the program output?

Thanks a bunch!

Comment by Ryan Stewart [ 16/Apr/12 ]

Running that gradlew just reuses the same daemon :\ Any other thoughts?

Comment by Szczepan Faber [ 16/Apr/12 ]

Thank you very much for checking this out. It means it's related to IDEA somehow. We would need logs from the IDEA.

@Denis, how can we get hold of the logs the tooling api writes when the IDEA plugin performs the refresh?

Comment by Denis Zhdanov [ 01/May/12 ]

Hi guys,

Sorry for the long delay, I was on vacation.

So, regarding the problem - gradle api output is located inside the IJ log (can be found from the IDE via 'Main menu | Help | Reveal Log' action). It's also possible to instruct the integration to use the tooling api at verbose mode. That is achieved if the IJ is started with the following system setting: 'gradle.api.verbose=true'

Btw, Szczepan, I also see multiple gradle daemon processes problem at my machine. It happens not all the time though. Am I right assuming that you tried to reproduce the problem at your environment from the IJ gradle integration (not gradle started from the command line)?

Comment by Ryan Stewart [ 03/May/12 ]

@Denis: I enabled verbose gradle output in IDEA, but it's really verbose, and the logs look like they're set to roll at 1M. How can I increase the file size and/or are there specific parts of the logs you want to see?

Also, I'm running build 117.281 now, and it's still happening. However, a couple of updates back, it seemed that the problem temporarily moved to the GradleApiFacadeImpl. When I did repeated refreshes, IDEA would start a new GradleApiFacadeImpl each time. Each facade would start its own gradle daemon, but the daemons would eventually die off. The facade seemed to stick around.

Comment by Denis Zhdanov [ 03/May/12 ]

Yes, there was a problem with unnecessary GradleApiFacadeImpl processes creation. It's fixed at the build 117.281.

Regarding the logs - you can tweak IJ log4j config at the $IDEA_HOME/bin/log4j.xml.

Btw, you should ask not me but Szczepan what parts of the logs are of our interest

Comment by Ryan Stewart [ 04/May/12 ]

I'll try to get to these logs today.

@Szczepan: What do you want to see from the logs?

Comment by Szczepan Faber [ 05/May/12 ]

Hey guys, sorry for late answer I was on on a short break.

I have a feeling that there's some bug in the way we try to match an existing daemon. The matching checks for the java location and certain crucial jvm options. The interesting log entries should look like (provided you're using recent gradle):

09:24:37.932 [DEBUG] [org.gradle.launcher.daemon.client.DefaultDaemonConnector] Found daemon (address: [11083afb-a5ff-4526-abad-ebb0265491b1 port:1725, addresses:[/127.0.0.1]], idle: true) however it's context does not match the desired criteria.
  Wanted: DefaultDaemonContext[uid=null,javaHome=D:\view_store\view\SCB_Test\TNT_Release\Build_Scripts\ThirdParty\was\AppSvr\java,daemonRegistryDir=C:\Documents and Settings\lloyro01\.gradle\daemon,pid=38440,idleTimeout=null,daemonOpts=-XX:MaxPermSize=256m,-XX:+HeapDumpOnOutOfMemoryError,-Xmx1024m,-Dfile.encoding=windows-1252].
  Found:  DefaultDaemonContext[uid=3ecdde36-061b-4904-8080-90d7074a8d09,javaHome=C:\Program Files\Java\jdk1.6.0_27,daemonRegistryDir=C:\Documents and Settings\lloyro01\.gradle\daemon,pid=49940,idleTimeout=10800000,daemonOpts=-Dfile.encoding=windows-1252].
  Looking for a different daemon...

Setting the tooling API to verbose should lets you see above output, however it's not strictly necessary. It should be enough to run the build/model with --debug which is now possible because Tooling API's LongRunningOperation.setArguments() lets you do it.

The interesting content of 'wanted:' and 'found:' from the logs are: java home and jvm options. I have a feeling that for some reason daemons are not reused because the matching does not work.

It also might be useful to compare the output from IDEA's logging with the sample application I provided because Ryan mentioned the sample app worked ok.

Let me know if you have any other question - I'm back at full speed on Monday, though.

Comment by Szczepan Faber [ 07/May/12 ]

Hey Ryan,

Any chances I could get hold of those logs?

Comment by Ryan Stewart [ 07/May/12 ]

Attaching verbose IntelliJ logs showing daemon creations.

Comment by Ryan Stewart [ 07/May/12 ]

I attached the complete logs from IntelliJ and the spawned gradle daemons from starting IntelliJ, running three gradle refreshes, and stopping IntelliJ, but I think you nailed it. Here's an excerpt:

09:05:08.151 [DEBUG] [org.gradle.launcher.daemon.client.DefaultDaemonConnector] Found daemon (address: [18954362-62c1-4ee6-ae55-e731c7c35ce4 port:51544, addresses:[/0:0:0:0:0:0:0:1%1, /127.0.0.1]], idle: true) however it's context does not match the desired criteria.
Wanted: DefaultDaemonContext[uid=null,javaHome=/home/ryan/dev/tools/java,daemonRegistryDir=/home/ryan/.gradle/daemon,pid=3419,idleTimeout=null,daemonOpts=-XX:MaxPermSize=256m,-XX:+HeapDumpOnOutOfMemoryError,-Xmx1024m,-Dfile.encoding=UTF-8].
Found:  DefaultDaemonContext[uid=e230c1c1-170f-45a1-a43c-cabe5135af4f,javaHome=/home/ryan/dev/tools/jdk1.7.0_04,daemonRegistryDir=/home/ryan/.gradle/daemon,pid=3885,idleTimeout=10800000,daemonOpts=-XX:MaxPermSize=256m,-XX:+HeapDumpOnOutOfMemoryError,-Xmx1024m,-Dfile.encoding=UTF-8].
Looking for a different daemon...

Specifically (spaced to align properties:

Wanted: DefaultDaemonContext[uid=null,                                javaHome=/home/ryan/dev/tools/java,       daemonRegistryDir=/home/ryan/.gradle/daemon,pid=3419,idleTimeout=null,    daemonOpts=-XX:MaxPermSize=256m,-XX:+HeapDumpOnOutOfMemoryError,-Xmx1024m,-Dfile.encoding=UTF-8].
Found:  DefaultDaemonContext[uid=e230c1c1-170f-45a1-a43c-cabe5135af4f,javaHome=/home/ryan/dev/tools/jdk1.7.0_04,daemonRegistryDir=/home/ryan/.gradle/daemon,pid=3885,idleTimeout=10800000,daemonOpts=-XX:MaxPermSize=256m,-XX:+HeapDumpOnOutOfMemoryError,-Xmx1024m,-Dfile.encoding=UTF-8].

The javaHome is different. I use a symlink named "java", which currently points at jdk1.7.0_04. Looking through the log, I see:

2012-05-07 09:03:17,205 [  36517]   INFO - .plugins.gradle.util.GradleLog - Instructing gradle to use java from /home/ryan/dev/tools/java
...
2012-05-07 09:03:19,912 [  39224]   INFO - ution.rmi.RemoteProcessSupport - 09:03:19.903 [INFO] [org.gradle.launcher.daemon.client.DefaultDaemonStarter] Starting daemon process: workingDir = /home/ryan/.gradle/daemon/1.0-rc-3, daemonArgs: [/home/ryan/dev/tools/java/bin/java, -XX:MaxPermSize=256m, -XX:+HeapDumpOnOutOfMemoryError, -Xmx1024m, -Dfile.encoding=UTF-8, -cp, /home/ryan/dev/tools/gradle/lib/gradle-launcher-1.0-rc-3.jar, org.gradle.launcher.daemon.bootstrap.GradleDaemon, 1.0-rc-3, /home/ryan/.gradle/daemon, 10800000, f013bc33-2263-48e3-a2d5-4e9923a79aa9, -XX:MaxPermSize=256m, -XX:+HeapDumpOnOutOfMemoryError, -Xmx1024m, -Dfile.encoding=UTF-8]
...
2012-05-07 09:03:21,686 [  40998]   INFO - ution.rmi.RemoteProcessSupport - 09:03:21.681 [INFO] [org.gradle.launcher.daemon.server.exec.ExecuteBuild] Executing build with daemon context: DefaultDaemonContext[uid=f013bc33-2263-48e3-a2d5-4e9923a79aa9,javaHome=/home/ryan/dev/tools/jdk1.7.0_04,daemonRegistryDir=/home/ryan/.gradle/daemon,pid=3456,idleTimeout=10800000,daemonOpts=-XX:MaxPermSize=256m,-XX:+HeapDumpOnOutOfMemoryError,-Xmx1024m,-Dfile.encoding=UTF-8]
...
2012-05-07 09:03:30,872 [  50184]   INFO - ution.rmi.RemoteProcessSupport - 09:03:30.835 [DEBUG] [org.gradle.api.internal.artifacts.ivyservice.IvyLoggingAdaper] setting 'java.home' to '/home/ryan/dev/tools/jdk1.7.0_04/jre'

If I'm reading that right, (#1) IntelliJ is telling gradle to use the Java at ~/dev/tools/java. (#2) Gradle says, "I'm starting with Java at ~/dev/tools/java." Somewhere in the middle, it resolves the symlink to the real directory, and then at #3, it starts using Java at ~/dev/tools/jdk1.7.0_04, and (#4) that's what it uses internally for everything. When IntelliJ comes back later and asks for the daemon running with Java at ~/dev/tools/java, it doesn't find one.

Comment by Szczepan Faber [ 07/May/12 ]

Well spotted. So in your environment the '/home/ryan/dev/tools/java' is a symlink to '/home/ryan/dev/tools/jdk1.7.0_04' ?

Comment by Szczepan Faber [ 07/May/12 ]

@Ryan, can you confirm my earlier question? I know you've said it but I just want to be sure

@Denis,

In GradleProjectResolverImpl, line 103 says:

modelBuilder.setJavaHome(new File(javaHome));

There's a bit of a conditional logic I wasn't able to completely trace. Can you tell me in what situations you actually set the java home on the model builder?

I have a feeling that in Ryan's case, the plugin sets the java home on the modelBuilder. The file is not canonicalized so the symlink is not resolved. Gradle daemon does use the canonical file, which means the symlink is resolved. So my current theory is that if the tooling api client provides a symlink to the setJavaHome method then the daemon cannot be connected any more. This needs to be fixed on our end. You can also try to pass canonical file via setJavaHome (in GradleProjectResolverImpl[103]) and validate my theory.

Comment by Ryan Stewart [ 07/May/12 ]

So in your environment the '/home/ryan/dev/tools/java' is a symlink to '/home/ryan/dev/tools/jdk1.7.0_04' ?

Yes, that's right.

Comment by Ryan Stewart [ 07/May/12 ]

And btw, I've verified that starting IDEA with JAVA_HOME set to the real JDK path instead of the symlink makes the problem go away. I also tried with IDEA_JDK set to the real path, but that didn't work. With JAVA_HOME set to the real path, invoking gradle from the command line and from IDEA will reuse the same daemon.

Comment by Szczepan Faber [ 08/May/12 ]

Thanks a lot Ryan for helping out with diagnosing this problem! I think we have enough data to reproduce & fix the problem. I'll let you know how's it going.

Cheers!

Comment by Denis Zhdanov [ 09/May/12 ]

Hello,

Regarding the modelBuilder.setJavaHome() - we try to ensure that the tooling api always has java to use. AFAIR one of our customers reported a situation when the gradle integration failed because the tooling api was unable to locate java at the target machine. That's why we instruct it explicitly. The logic is contained here - https://github.com/JetBrains/intellij-community/blob/master/plugins/gradle/src/org/jetbrains/plugins/gradle/remote/GradleJavaHelper.java.

I.e. it allows to customize java to use by the gradle integration; falls back to the JAVA_HOME (if any); and eventually uses current jre if none of above passes.

Comment by Szczepan Faber [ 09/May/12 ]

Thanks for the confirmation, Denis.

The fix has been pushed to gradle master. I'll go out with Gradle 1.1.

Comment by Beenish Zaidi [ 20/Jun/12 ]

Hi.
i am using intellij 11 build number IU-117.418 but same issue still exists. The fix has not been
put into this release. Please help how to resolve this issue.
BR,
Ben

Comment by Denis Zhdanov [ 20/Jun/12 ]

What gradle version do you use?

Comment by Guy Brand [ 20/Jun/12 ]

@Beenish Zaidi: Don't use a symlink inside JAVA_HOME. That fixed it on my machine (Ubuntu 64 Bit, Idea 11)

Comment by Beenish Zaidi [ 20/Jun/12 ]

Hi Denis,
I am using gradle-1.0-rc-3.

@Guy, i am not using UBuntu, i am using Windows 7 64-Bit.

Thanks,
Ben

Comment by Beenish Zaidi [ 20/Jun/12 ]

Hi Denis,

I just changed into latest release

http://gradle.org/downloads which is Gradle 1.0

Still the problem exisits.

Thanks,
Ben

Comment by Denis Zhdanov [ 20/Jun/12 ]

@Beenish: can you check your logs for the information requested by Szczepan earlier? It's not clear whether you're experiencing the same problem as Guy or not.

Comment by Beenish Zaidi [ 20/Jun/12 ]

Hi,
I am attaching my idea log file. I think so issue is something different. Can you please verify also?
Ben

Comment by Denis Zhdanov [ 20/Jun/12 ]

The log file contains information about the exception but doesn't provide enough details. Need to check logging rules there. Will comment here later.

Denis

Comment by Beenish Zaidi [ 20/Jun/12 ]

Dear Denis,
No issues. I will await for further feedback.
Thanks,
Ben

Comment by Szczepan Faber [ 20/Jun/12 ]

This issue was fixed in 1.1 (see the fix for field above) so Beenish needs to use gradle 1.1 to resolve the problem. I think it's ok with Denis still uses the tooling api 1.0. @Beenish, please use 1.1 nightly: http://gradle.org/nightly

Comment by Beenish Zaidi [ 21/Jun/12 ]

Hello faber,
Issue is resolved by replacing gradle with nightly build 1.1. I am unable to get what
the issue was, can your briefly elaborate?
Ben

Comment by Ryan Stewart [ 21/Jun/12 ]

@Beenish: It's all explained in these comments before you started adding more, including the fact that the fix is in 1.1, not 1.0.

Comment by Jayson Minard [ 13/Oct/12 ]

In Current IntelliJ 11 (117.798) on Mac OS X (Mountain Lion) I still have cases where more than one Daemon are started. With the following settings I limit it to one or two, but if IntelliJ starts more than one Gradle refresh at a time then you can still have more Daemons.

My settings in my ~/.profile:

export GRADLE_HOME=~/DEV/Gradle-1.2
export PATH=$GRADLE_HOME/bin:$PATH

export JAVA_HOME=`/usr/libexec/java_home -v1.6`
export PATH=${JAVA_HOME}/bin:$PATH

launchctl setenv JAVA_HOME $JAVA_HOME

alias g='gradle --daemon'
alias gradle='gradle --daemon'
alias gv='ps -ef | grep GradleDaemon | grep -v grep'
alias gs='gradle --stop'

And in my /Applications/IntelliJ\ IDEA\ 11.app/bin/idea.properties

gradle.java.home=/System/Library/Java/JavaVirtualMachines/1.6.0.jdk/Contents/Home

now, ways to end up with IntelliJ doing more than one Gradle refresh at a time:

  • click the refresh Gradle button twice quickly before it disables (there is a lag there).
  • when you have a set of green "Gradle local entities" import one of them, and while it is running, import another, and while that is running, import another. Each creates a new Gradle refresh action.

You will then see many background processes running in Intellij. If you view the processes window, it shows multiple refreshes running at same time, all doing the same work. And for each additional one you end up with another Gradle Daemon process.

Otherwise the command-line and IntelliJ will share one daemon nicely, but the multiple refreshes breaks that.

So it is important to periodically stop the daemons before the machine runs out of memory...

Comment by Jayson Minard [ 13/Oct/12 ]

A last note, does the import of a "Gradle local entity" need to refresh the full project every time? On a large project this is causing 1 minute pauses every time something is touched in the Gradle tree.

Comment by Etienne Studer [ 14/Oct/12 ]

I can fully confirm the observations made by Jayson Minard. We face exactly the same issues.

Comment by Szczepan Faber [ 15/Oct/12 ]

For my sanity, can you confirm that the Gradle version the JetGradle uses is at least 1.1? JetGradle does not respect GRADLE_HOME from the env AFAIK (and I don't think it should). There's UI configuration for it in JetGradle.

JetGradle does not respect the Gradle wrapper setting, too, which is unfortunate, but I'm hoping it will get fixed in JetGradle at some point (please vote for this ticket in the JetGradle tracker .

Tooling api does fork a new daemon if the current one is busy. Rapidly clicking refresh causes extra daemons for that reason I think.

Tooling api does not implement any synchronization rules (other than most clases are designed to be thread-safe - see the javadoc for more details). If users request multiple operations concurrently the tooling API will attempt to execute them concurrently. At the moment we don't plan to change that behavior in the tooling api.

It's up to the client to synchronize the operations that should not execute concurrently. For example, I think JetGradle should not allow multiple concurrent entire-project refreshes. Yet, it should allow running tasks concurrently (for example when the user wants to run :a:foo and :b:bar concurrently).

Comment by Etienne Studer [ 15/Oct/12 ]

I'm on 1.2. To me, too, this seems more like an IDEA issue than a Gradle issue.

Comment by Jayson Minard [ 15/Oct/12 ]

Yes, 1.2. My above settings work around the issues with lining up the JAVA_HOME directories used by everything; which causes multiple daemon processes if they are not identical. The rest are just logic issues with IntelliJ's use of the tooling API, maybe...

I'll drop a note over in their tracker.

Comment by Jayson Minard [ 15/Oct/12 ]

I commented on both of the old IntelliJ bug reports IDEA-84443 and IDEA-88068 ... and created this one specifically for concurrent refreshes: IDEA-92954

Comment by Szczepan Faber [ 15/Oct/12 ]

Thanks a lot!!! It is really helpful if JetGradle receives reports from our users, not only from us - Gradle devs.

Generated at Wed Jun 30 12:16:13 CDT 2021 using Jira 8.4.2#804003-sha1:d21414fc212e3af190e92c2d2ac41299b89402cf.