[GRADLE-1797] tooling api should not reset java logging when embedded Created: 15/Sep/11  Updated: 04/Jan/13  Resolved: 21/Nov/11

Status: Resolved
Project: Gradle
Affects Version/s: 1.0-milestone-3, 1.0-milestone-4
Fix Version/s: 1.0-milestone-7

Type: Bug
Reporter: Szczepan Faber Assignee: Szczepan Faber
Resolution: Fixed Votes: 1


 Description   
Problem

To support reporting and output listeners, gradle does advanced manipulation of logging, e.g. resets the java logging and replaces standard streams, etc. This approach is fine if gradle owns the process (e.g. running gradle from console, running against daemon, etc.). However, when gradle is embedded via tooling api then it shouldn't really manipulate the jvm-global logging commodities.

Resolution

Gradle does not manipulate jvm-global logging commodities when embedded (e.g. when Tooling Api used).

Symptoms

When tooling-api is used inside of the NetBeans container (e.g. in gradle NetBeans plugin) then NB editors break and stop showing contents. Reported initially by geertjan.wielenga@oracle.com

Steps to reproduce:
  1. Install NetBeans IDE 7.0.1.
  2. Checkout sources of the gradle NB support (Geertjan can provide access or attach the sources zip to this issue) and open the project in NB
  3. Bump the memory settings to avoid permgen errors. Add following line to the platform.properties file: 
    run.args.extra=-J-XX:MaxPermSize=512m
  4. Right-click the module in 7.0.1 and choose Run. A new instance of NetBeans starts up, with the module installed.
  5. If the project does not build you need to re-add some library dependencies. In my case I needed to delete Project UI Api library and add it again.
  6. Go to the "Tools" menu in the main menu bar and choose "Options". (On Mac options are at apple+i)
  7. Click the "Gradle" tab and set the location of your Gradle distribution on disk. (Do not use the optional section for verifying the Gradle location, because that is going to do a Gradle build, which will create the problem too soon.). I was able to reproduce with M3, M4 and master.
  8. Now go to the New Project dialog (Ctrl-Shift-N) and then Java | Java Application. Click Next and then click Finish.
  9. Right-click "Gradle Project Files" (or the Gradle project node or any node except Libraries) and choose New | Desktop. Click Finish.
  10. If the Navigator isn't open (Window | Navigating | Navigator), open it, and when you select the Gradle file in "Gradle Project File", you will see all the tasks. And, from now onwards, all the documents you create in the IDE will be blank in the editor.

Expected behavior: editors show file contents.

It appears that when we do connection.getModel(...) and effectively tell the daemon to do something (regardless if the deamon was already started or has just been started) then editors in NB stop showing any content (tested with couple various editors, e.g. java,html,etc). You can click on a java file but the editor is blank (even though the file has contents - checked outside NB).

(DEPRECATED We used to think that the problem is due to the daemon) Potential resolutions/next steps:

  1. Provide a switch in tooling-api to work in daemon-less way. Geertjan is very keen on that. This could help diagnosing the problem. (Szczepan) I'm ok with that switch, it's even consistent with our main api, where such switch already exists.
  2. Show that issue to some NetBeans overlord who knows the nitty-gritty behind loading the editor contents in NB. E.g. what can possibly go wrong, if contents do not load then where is the stack trace, etc.
  3. Do some further debugging with NB + local versions of tooling api/gradle. This way we can find out what exactly the problem is, though it might take time.

 Comments   
Comment by Adam Murdoch [ 15/Sep/11 ]

We should start with option 1, as such a switch already exists as DefaultGradleConnector.embedded(boolean). (don't specify the distribution to use - leave it as the default).

If things work with embedded(true), we should dig to find out why embedded(false) does not work. And of course, if things don't work with embedded(true), we should also dig to find out why neither of them work. ie, we should do 3 as well as 1.

Comment by Geertjan Wielenga [ 23/Sep/11 ]

I was explicitly told by Szczepan to not use DefaultGradleConnector.

Comment by Szczepan Faber [ 23/Sep/11 ]

Right, because it's an internal class. However, it might be useful to use it just for debugging - to see if it helps resolve the issue. If you're using embedded(true) make sure you don't use some other configuration methods (like setting the distro to use) because they may override the embedded setting and you're back with the daemon process. This is not documented explicitly because DefaultGradleConnector is an internal class.

Hope that helps!

Comment by Geertjan Wielenga [ 26/Sep/11 ]

the problem is in the following stack trace:

java.util.logging.Logger.updateEffectiveLevel(Logger.java:1428)
java.util.logging.Logger.setLevel(Logger.java:1134)
java.util.logging.LogManager.resetLogger(LogManager.java:702)
java.util.logging.LogManager.reset(LogManager.java:676)
org.gradle.logging.internal.JavaUtilLoggingConfigurer.configure(JavaUtilLoggingConfigurer.java:36)
org.gradle.logging.internal.DefaultLoggingConfigurer.configure(DefaultLoggingConfigurer.java:34)
org.gradle.logging.internal.LoggingSystemAdapter.restore(LoggingSystemAdapter.java:50)
org.gradle.logging.internal.DefaultLoggingManager$StartableLoggingSystem.stop(DefaultLoggingManager.java:208)
org.gradle.messaging.concurrent.CompositeStoppable.stop(CompositeStoppable.java:91)
org.gradle.logging.internal.DefaultLoggingManager.stop(DefaultLoggingManager.java:69)
org.gradle.logging.internal.DefaultLoggingManager.stop(DefaultLoggingManager.java:31)
org.gradle.tooling.internal.provider.LoggingBridgingGradleLauncherActionExecuter.execute(LoggingBridgingGradleLauncherActionExecuter.java:58)
org.gradle.tooling.internal.provider.LoggingBridgingGradleLauncherActionExecuter.execute(LoggingBridgingGradleLauncherActionExecuter.java:30)
org.gradle.tooling.internal.provider.DefaultConnection.run(DefaultConnection.java:78)
org.gradle.tooling.internal.provider.DefaultConnection.getModel(DefaultConnection.java:72)
org.gradle.tooling.internal.consumer.LazyConnection$3.run(LazyConnection.java:90)
org.gradle.tooling.internal.consumer.LazyConnection$3.run(LazyConnection.java:88)
org.gradle.tooling.internal.consumer.LazyConnection.withConnection(LazyConnection.java:98)
org.gradle.tooling.internal.consumer.LazyConnection.getModel(LazyConnection.java:88)
org.gradle.tooling.internal.consumer.ProgressLoggingConnection$2.run(ProgressLoggingConnection.java:61)
org.gradle.tooling.internal.consumer.ProgressLoggingConnection$2.run(ProgressLoggingConnection.java:59)
org.gradle.tooling.internal.consumer.ProgressLoggingConnection.run(ProgressLoggingConnection.java:74)
org.gradle.tooling.internal.consumer.ProgressLoggingConnection.getModel(ProgressLoggingConnection.java:59)
org.gradle.tooling.internal.consumer.DefaultAsyncConnection$2.run(DefaultAsyncConnection.java:53)
org.gradle.tooling.internal.consumer.DefaultAsyncConnection$2.run(DefaultAsyncConnection.java:51)
org.gradle.tooling.internal.consumer.DefaultAsyncConnection$3.run(DefaultAsyncConnection.java:71)
org.gradle.messaging.concurrent.DefaultExecutorFactory$StoppableExecutorImpl$1.run(DefaultExecutorFactory.java:63)
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
java.lang.Thread.run(Thread.java:680)

Gradle's DefaultConnection resets the log system. It goes through some logging system abstraction but it ends in the JavaUtilLoggingConfigurer.configure() which does the following:

LogManager.getLogManager().reset();
SLF4JBridgeHandler.install();
Logger.getLogger("").setLevel(java.util.logging.Level.FINE);
configured = true;

Important is 1st and 3rd line. On the first line, Gradle resets the log system (it closes and removes all the log handlers and sets the log level to default). On the third line it sets the level of the default logger to FINE. It causes that the BaseDocument.LOG_EDT is set to FINE level. Gradle should not do the reset as it removes all existing log handlers.

Comment by Geertjan Wielenga [ 26/Sep/11 ]

Gradle should not reset the LogManager. It's really bad as it affects all loggers
in NetBeans IDE and probably other tools too.

Comment by Rajmahendra Hegde [ 17/Oct/11 ]

just to speedup work ... i am one of those NetBeans and Gradle lover event use gradle in scala development.. i love to see this bug to be fixed soon and release of the Netbeans Gradle plugin.

Comment by Szczepan Faber [ 16/Nov/11 ]

The root cause is fixed. NetBeans editors are safe now. However, ehen using NetBeans Gradle plugin I came across some other problems. I created a separate ticket for it: GRADLE-1933

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