Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add logback tracing to Java LS #2116

Merged
merged 1 commit into from
Jun 22, 2022
Merged

Conversation

snjeza
Copy link
Contributor

@snjeza snjeza commented Jun 2, 2022

Fixes #2108

You can test in the following way

  • add -Djdt.ls.debug=true to java.jdt.ls.vmargs
  • open a maven project
  • check the Java LS server log

You can override it using -Dlogback.configurationFile=<your-logback.xml>

Notice: Now, m2e.core requires Java-17

Signed-off-by: Snjezana Peco snjezana.peco@redhat.com

@rgrunber
Copy link
Contributor

rgrunber commented Jun 2, 2022

Nice. If this works, we can hopefully close out redhat-developer/vscode-java#2375 (comment)

Is it possible to combine jdt.ls.logback into jdt.ls.start to have just 1 extra bundle ? Or does the requirement that jdt.ls.logback be a fragment of logback.classic mean they must be separate. Could the JavaLanguageServerStart.java not be added inside jdt.ls.core since we no longer need to call setProperty very early ?

@snjeza
Copy link
Contributor Author

snjeza commented Jun 2, 2022

Is it possible to combine jdt.ls.logback into jdt.ls.start to have just 1 extra bundle ?

No, it isn't. jdt.ls.start have to start first so can't be a fragment.

Could the JavaLanguageServerStart.java not be added inside jdt.ls.core since we no longer need to call setProperty very early ?

No, it couldn't. We have to call setProperty very early if exists ch.qos.logback

@testforstephen
Copy link
Contributor

Having a separate start plugin to set logback property looks like kind of hack. I don't get the point why we cannot do it in jdt.ls bundle.

@snjeza
Copy link
Contributor Author

snjeza commented Jun 6, 2022

Having a separate start plugin to set logback property looks like kind of hack. I don't get the point why we cannot do it in jdt.ls bundle.

@testforstephen You may want to take a look at #2096 (comment) and #2116 (comment)

@rgrunber
Copy link
Contributor

rgrunber commented Jun 6, 2022

Also, for the nicer solution of logging directly to Eclipse's logs, I think the logback framework (ch.qos.logback.classic?) only checks its classpath for custom appenders, so effectively that means we need to use Fragment-Host. Not sure we can do that for jdt.ls.core since a fragment is not considered a bundle with its own Activator start/stop. See https://github.com/eclipse-m2e/m2e-core/blob/master/org.eclipse.m2e.logback.appender/META-INF/MANIFEST.MF#L8 , and the custom appender at https://github.com/eclipse-m2e/m2e-core/blob/master/org.eclipse.m2e.logback.appender/src/org/eclipse/m2e/logback/appender/EclipseLogAppender.java . Unfortunately we can't use that because of the UI dependencies.

@snjeza snjeza changed the title [WIP] Add logback tracing to Java LS Add logback tracing to Java LS Jun 7, 2022
@snjeza
Copy link
Contributor Author

snjeza commented Jun 9, 2022

test this please

1 similar comment
@snjeza
Copy link
Contributor Author

snjeza commented Jun 9, 2022

test this please

@snjeza snjeza removed the in progress label Jun 9, 2022
@rgrunber
Copy link
Contributor

rgrunber commented Jun 10, 2022

Just one observation about the logging. Importing a project like eclipse/lemminx I see about 15 messages going into the server logs. However, I remember seeing many more when I was able to enable verbose/debug logging. For example :

.out-jdt.ls-20220610140605.log

It's a bit excessive, but is it possible to have control over the DEBUG messages also ? i think they're the ones that are currently missing. I thought adding a case Level.DEBUG_INT: in EclipseLogAppender would solve it but it doesn't seem to have worked.

@snjeza
Copy link
Contributor Author

snjeza commented Jun 10, 2022

It's a bit excessive, but is it possible to have control over the DEBUG messages also ? i think they're the ones that are currently missing. I thought adding a case Level.DEBUG_INT: in EclipseLogAppender would solve it but it doesn't seem to have worked.

checking...
@rgrunber I have update the PR.

@snjeza
Copy link
Contributor Author

snjeza commented Jun 10, 2022

@rgrunber Could you, please, check again?

@snjeza
Copy link
Contributor Author

snjeza commented Jun 10, 2022

test this please

3 similar comments
@snjeza
Copy link
Contributor Author

snjeza commented Jun 11, 2022

test this please

@snjeza
Copy link
Contributor Author

snjeza commented Jun 11, 2022

test this please

@snjeza
Copy link
Contributor Author

snjeza commented Jun 11, 2022

test this please

@rgrunber
Copy link
Contributor

Works for me when -Djdt.ls.debug=true is set, which is what we want. Printing that much data normally would probably be annoying for users, as it would take up space.

I just tried disabling the jdt.ls.start bundle and moving the functionality into jdt.ls.core's JavaServerPlugin. I'm still able to see the data in the server logs. Seems to work consistently. I thought this shouldn't work. If it's possible to have things working this way, it would be preferable.

Note that, I don't mind regressing on having the ability to supply a custom logback file through system properties. It was a nice-to-have feature, but ultimately, the most important thing is just being able to log the data with some sane defaults (we can provide).

diff
diff --git a/org.eclipse.jdt.ls.core/META-INF/MANIFEST.MF b/org.eclipse.jdt.ls.core/META-INF/MANIFEST.MF
index 00190061..c53b74b2 100644
--- a/org.eclipse.jdt.ls.core/META-INF/MANIFEST.MF
+++ b/org.eclipse.jdt.ls.core/META-INF/MANIFEST.MF
@@ -30,7 +30,10 @@ Require-Bundle: org.eclipse.core.runtime;bundle-version="3.12.0",
  org.eclipse.xtext.xbase.lib,
  org.eclipse.core.filesystem;bundle-version="1.7.0",
  org.eclipse.jdt.apt.pluggable.core;bundle-version="1.2.0";resolution:=optional,
- org.eclipse.m2e.apt.core;bundle-version="1.3.0";resolution:=optional
+ org.eclipse.m2e.apt.core;bundle-version="1.3.0";resolution:=optional,
+ ch.qos.logback.classic;bundle-version="1.2.3",
+ ch.qos.logback.core;bundle-version="1.2.3",
+ org.slf4j.api;bundle-version="1.7.30"
 Export-Package: org.eclipse.jdt.ls.core.internal;x-friends:="org.eclipse.jdt.ls.tests,org.eclipse.jdt.ls.tests.syntaxserver",
  org.eclipse.jdt.ls.core.internal.codemanipulation;x-friends:="org.eclipse.jdt.ls.tests",
  org.eclipse.jdt.ls.core.internal.commands;x-friends:="org.eclipse.jdt.ls.tests",
diff --git a/org.eclipse.jdt.ls.core/build.properties b/org.eclipse.jdt.ls.core/build.properties
index 829276d3..3ca486ad 100644
--- a/org.eclipse.jdt.ls.core/build.properties
+++ b/org.eclipse.jdt.ls.core/build.properties
@@ -7,6 +7,8 @@ bin.includes = META-INF/,\
                lib/remark-1.2.0.jar,\
                lifecycle-mapping-metadata.xml,\
                plugin.properties,\
+               logback.xml,\
+               emptylogback.xml,\
                gradle/checksums/checksums.json,\
                gradle/checksums/versions.json
 src.includes = src/
diff --git a/org.eclipse.jdt.ls.core/src/org/eclipse/jdt/ls/core/internal/JavaLanguageServerPlugin.java b/org.eclipse.jdt.ls.core/src/org/eclipse/jdt/ls/core/internal/JavaLanguageServerPlugin.java
index 33fea334..e85133e9 100644
--- a/org.eclipse.jdt.ls.core/src/org/eclipse/jdt/ls/core/internal/JavaLanguageServerPlugin.java
+++ b/org.eclipse.jdt.ls.core/src/org/eclipse/jdt/ls/core/internal/JavaLanguageServerPlugin.java
@@ -24,9 +24,12 @@ import java.io.PrintStream;
 import java.net.Authenticator;
 import java.net.InetSocketAddress;
 import java.net.PasswordAuthentication;
+import java.net.URL;
 import java.nio.channels.AsynchronousServerSocketChannel;
 import java.nio.channels.AsynchronousSocketChannel;
 import java.nio.channels.Channels;
+import java.nio.file.Files;
+import java.nio.file.StandardCopyOption;
 import java.text.SimpleDateFormat;
 import java.util.Date;
 import java.util.concurrent.ExecutionException;
@@ -81,11 +84,23 @@ import org.osgi.framework.Bundle;
 import org.osgi.framework.BundleContext;
 import org.osgi.framework.BundleException;
 import org.osgi.util.tracker.ServiceTracker;
+import org.slf4j.ILoggerFactory;
+import org.slf4j.LoggerFactory;
+import org.slf4j.helpers.SubstituteLoggerFactory;
 
 import com.google.common.base.Throwables;
 
+import ch.qos.logback.classic.LoggerContext;
+import ch.qos.logback.classic.joran.JoranConfigurator;
+import ch.qos.logback.core.joran.spi.JoranException;
+import ch.qos.logback.core.util.StatusPrinter;
+
 public class JavaLanguageServerPlugin extends Plugin {
 
+	private static final String LOGBACK_CONFIG_FILE_PROPERTY = "logback.configurationFile";
+	private static final String LOGBACK_DEFAULT_FILENAME = "logback.xml";
+	private static final String LOGBACK_EMPTY_FILENAME = "emptylogback.xml";
+
 	private static final String JDT_UI_PLUGIN = "org.eclipse.jdt.ui";
 	public static final String MANUAL = "Manual";
 	public static final String DIRECT = "Direct";
@@ -173,6 +188,22 @@ public class JavaLanguageServerPlugin extends Plugin {
 		JavaLanguageServerPlugin.pluginInstance = this;
 		setPreferenceNodeId();
 
+		if (System.getProperty(LOGBACK_CONFIG_FILE_PROPERTY) == null) {
+			File stateDir = getStateLocation().toFile();
+			String fileName = isDebug ? LOGBACK_DEFAULT_FILENAME : LOGBACK_EMPTY_FILENAME;
+			File configFile = new File(stateDir, fileName);
+			if (!configFile.isFile()) {
+				try (InputStream is = bundleContext.getBundle().getEntry(fileName).openStream(); FileOutputStream fos = new FileOutputStream(configFile)) {
+					Files.copy(is, configFile.toPath(), StandardCopyOption.REPLACE_EXISTING);
+				} catch (Exception e) {
+					logException(e.getMessage(), e);
+				}
+			}
+			loadConfiguration(configFile.toURI().toURL());
+			// ch.qos.logback.classic.util.ContextInitializer.CONFIG_FILE_PROPERTY
+			// System.setProperty(LOGBACK_CONFIG_FILE_PROPERTY, configFile.getAbsolutePath());
+		}
+
 		if (JDTEnvironmentUtils.isSyntaxServer()) {
 			disableServices();
 			preferenceManager = new PreferenceManager();
@@ -200,6 +231,42 @@ public class JavaLanguageServerPlugin extends Plugin {
 		}
 	}
 
+	public static void loadConfiguration(URL configFile) throws JoranException {
+		LoggerContext lc = getLoggerContext();
+		if (lc == null) {
+			logError("Cannot initialize logback");
+			return;
+		}
+		lc.reset();
+		JoranConfigurator configurator = new JoranConfigurator();
+		configurator.setContext(lc);
+		configurator.doConfigure(configFile);
+		StatusPrinter.printInCaseOfErrorsOrWarnings(lc);
+		// logJavaProperties(LoggerFactory.getLogger(JavaLanguageServerStart.class));
+	}
+
+	private static LoggerContext getLoggerContext() {
+		ILoggerFactory loggerFactory = LoggerFactory.getILoggerFactory();
+
+		for (int i = 0; loggerFactory instanceof SubstituteLoggerFactory && i < 100; i++) {
+			try {
+				Thread.sleep(50);
+			} catch (InterruptedException e) {
+				Thread.currentThread().interrupt(); // ignore but re-interrupt
+			}
+			loggerFactory = LoggerFactory.getILoggerFactory();
+		}
+
+		if (loggerFactory instanceof LoggerContext) {
+			return (LoggerContext) loggerFactory;
+		}
+		String msg = loggerFactory == null ? // Is null possible?
+				"SLF4J logger factory is null" //$NON-NLS-1$
+				: "SLF4J logger factory is not an instance of LoggerContext: " + loggerFactory.getClass().getName(); // $NON-NLS-1$
+		logInfo(msg);
+		return null;
+	}
+
 	private void disableServices() {
 		try {
 			ProjectsManager.setAutoBuilding(false);
diff --git a/org.eclipse.jdt.ls.product/languageServer.product b/org.eclipse.jdt.ls.product/languageServer.product
index 404c10ea..d8ccede9 100644
--- a/org.eclipse.jdt.ls.product/languageServer.product
+++ b/org.eclipse.jdt.ls.product/languageServer.product
@@ -57,7 +57,6 @@
       <plugin id="org.eclipse.jdt.launching.macosx"/>
       <plugin id="org.eclipse.jdt.ls.core"/>
       <plugin id="org.eclipse.jdt.ls.logback.appender" fragment="true"/>
-      <plugin id="org.eclipse.jdt.ls.start"/>
       <plugin id="org.eclipse.m2e.apt.core"/>
       <plugin id="org.eclipse.m2e.core"/>
       <plugin id="org.eclipse.m2e.jdt"/>
@@ -77,7 +76,6 @@
       <plugin id="org.eclipse.equinox.common" autoStart="true" startLevel="2" />
       <plugin id="org.eclipse.jdt.core" autoStart="false" startLevel="0" />
       <plugin id="org.eclipse.jdt.launching" autoStart="false" startLevel="0" />
-      <plugin id="org.eclipse.jdt.ls.start" autoStart="true" startLevel="0" />
    </configurations>
 
    <preferencesInfo>

@snjeza
Copy link
Contributor Author

snjeza commented Jun 14, 2022

Seems to work consistently.

Could you try to create a vsix with Java 17 jre and start a maven project in a new workspace? See #2096 (comment)

Note that, I don't mind regressing on having the ability to supply a custom logback file through system properties. It was a nice-to-have feature, but ultimately, the most important thing is just being able to log the data with some sane defaults

You can try to set -Dlogback.configurationFile=<your_logback.xml> jvmargs. It should work.

@rgrunber
Copy link
Contributor

Seems to work consistently.

Could you try to create a vsix with Java 17 jre and start a maven project in a new workspace? See #2096 (comment)

Note that, I don't mind regressing on having the ability to supply a custom logback file through system properties. It was a nice-to-have feature, but ultimately, the most important thing is just being able to log the data with some sane defaults

You can try to set -Dlogback.configurationFile=<your_logback.xml> jvmargs. It should work.

You're right. It would break that case.

private static final String LOGBACK_CONFIG_FILE_PROPERTY = "logback.configurationFile";
private static final String LOGBACK_DEFAULT_FILENAME = "logback.xml";
private static final String LOGBACK_EMPTY_FILENAME = "emptylogback.xml";
public static final String PLUGIN_ID = "org.eclipse.jdt.ls.start";
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If we have to create a new bundle to solve this problem, I would rename it from "org.eclispe.jdt.ls.start" to "org.eclipse.jdt.ls.logback", and make this bundle only used for handling logback logic.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Fixed.

Comment on lines 77 to 81
try {
Platform.getBundle(CORE_PLUGIN_ID).start(Bundle.START_TRANSIENT);
} catch (BundleException e) {
logException(e.getMessage(), e);
}
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why do we need to start jdt.ls.core bundle manually here? It looks unnecessary for me.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You are right. I have removed it.

@snjeza
Copy link
Contributor Author

snjeza commented Jun 15, 2022

@rgrunber @testforstephen I have updated the PR. I have also updated the target platform to 4.24 because 4.24-I-builds doesn't exist.
re failing tests, see #2123

@snjeza snjeza force-pushed the issue-2108 branch 3 times, most recently from 0154920 to e57bd57 Compare June 16, 2022 16:37
@rgrunber
Copy link
Contributor

rgrunber commented Jun 16, 2022

@testforstephen , so currently, the m2e logs are only appended to the .log (JDT-LS runtime logs) file when -Djdt.ls.debug=true is added to java.jdt.ls.vmargs. So this change shouldn't add any more data to the logs by default, as one must explicitly add the setting.

on loading a project like spring-petclinic :
Regular logging (no m2e logging) prints about 16KB (197 lines) for me
Debug logging (with m2e logging) prints about 220KB (3509 lines) for me

@snjeza
Copy link
Contributor Author

snjeza commented Jun 16, 2022

test this please

@testforstephen
Copy link
Contributor

@testforstephen , so currently, the m2e logs are only appended to the .log (JDT-LS runtime logs) file when -Djdt.ls.debug=true is added to java.jdt.ls.vmargs. So this change shouldn't add any more data to the logs by default, as one must explicitly add the setting.

on loading a project like spring-petclinic : Regular logging (no m2e logging) prints about 16KB (197 lines) for me Debug logging (with m2e logging) prints about 220KB (3509 lines) for me

Good to know it. Since it won't append to the .log file by default, so it's not a problem for language server daemon.

@testforstephen
Copy link
Contributor

testforstephen commented Jun 17, 2022

When I execute "Java: Clean Java Language Server Workspace" commad and reload window, it reports the following exception.

!ENTRY org.eclipse.jdt.ls.logback 4 0 2022-06-17 11:25:55.056
!MESSAGE C:\Users\myName\AppData\Roaming\Code\User\workspaceStorage\c2d6260b73da6e426b91d7bd9c5b1036\redhat.java\jdt_ws\.metadata\.plugins\org.eclipse.jdt.ls.logback\emptylogback.xml: The process cannot access the file because it is being used by another process
!STACK 0
java.nio.file.FileSystemException: C:\Users\myName\AppData\Roaming\Code\User\workspaceStorage\c2d6260b73da6e426b91d7bd9c5b1036\redhat.java\jdt_ws\.metadata\.plugins\org.eclipse.jdt.ls.logback\emptylogback.xml: The process cannot access the file because it is being used by another process
	at java.base/sun.nio.fs.WindowsException.translateToIOException(WindowsException.java:92)
	at java.base/sun.nio.fs.WindowsException.rethrowAsIOException(WindowsException.java:103)
	at java.base/sun.nio.fs.WindowsException.rethrowAsIOException(WindowsException.java:108)
	at java.base/sun.nio.fs.WindowsFileSystemProvider.implDelete(WindowsFileSystemProvider.java:275)
	at java.base/sun.nio.fs.AbstractFileSystemProvider.deleteIfExists(AbstractFileSystemProvider.java:110)
	at java.base/java.nio.file.Files.deleteIfExists(Files.java:1191)
	at java.base/java.nio.file.Files.copy(Files.java:3148)
	at org.eclipse.jdt.ls.logback.JavaLanguageServerStart.start(JavaLanguageServerStart.java:66)
	at org.eclipse.osgi.internal.framework.BundleContextImpl$2.run(BundleContextImpl.java:818)
	at org.eclipse.osgi.internal.framework.BundleContextImpl$2.run(BundleContextImpl.java:1)
	at java.base/java.security.AccessController.doPrivileged(AccessController.java:569)
	at org.eclipse.osgi.internal.framework.BundleContextImpl.startActivator(BundleContextImpl.java:810)
	at org.eclipse.osgi.internal.framework.BundleContextImpl.start(BundleContextImpl.java:767)
	at org.eclipse.osgi.internal.framework.EquinoxBundle.startWorker0(EquinoxBundle.java:1032)
	at org.eclipse.osgi.internal.framework.EquinoxBundle$EquinoxModule.startWorker(EquinoxBundle.java:371)
	at org.eclipse.osgi.container.Module.doStart(Module.java:605)
	at org.eclipse.osgi.container.Module.start(Module.java:468)
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel$2.run(ModuleContainer.java:1847)
	at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor$1$1.execute(EquinoxContainerAdaptor.java:136)
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1840)
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1783)
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1745)
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1667)
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1)
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234)
	at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:345)

!ENTRY org.eclipse.jdt.ls.logback 4 0 2022-06-17 11:25:55.152
!MESSAGE FrameworkEvent ERROR
!STACK 0
org.osgi.framework.BundleException: Exception in org.eclipse.jdt.ls.logback.JavaLanguageServerStart.start() of bundle org.eclipse.jdt.ls.logback.
	at org.eclipse.osgi.internal.framework.BundleContextImpl.startActivator(BundleContextImpl.java:839)
	at org.eclipse.osgi.internal.framework.BundleContextImpl.start(BundleContextImpl.java:767)
	at org.eclipse.osgi.internal.framework.EquinoxBundle.startWorker0(EquinoxBundle.java:1032)
	at org.eclipse.osgi.internal.framework.EquinoxBundle$EquinoxModule.startWorker(EquinoxBundle.java:371)
	at org.eclipse.osgi.container.Module.doStart(Module.java:605)
	at org.eclipse.osgi.container.Module.start(Module.java:468)
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel$2.run(ModuleContainer.java:1847)
	at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor$1$1.execute(EquinoxContainerAdaptor.java:136)
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1840)
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1783)
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1745)
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1667)
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1)
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234)
	at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:345)
Caused by: ch.qos.logback.core.joran.spi.JoranException: Problem parsing XML document. See previously reported errors.
	at ch.qos.logback.core.joran.event.SaxEventRecorder.recordEvents(SaxEventRecorder.java:65)
	at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:151)
	at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:110)
	at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:53)
	at org.eclipse.jdt.ls.logback.JavaLanguageServerStart.loadConfiguration(JavaLanguageServerStart.java:110)
	at org.eclipse.jdt.ls.logback.JavaLanguageServerStart.start(JavaLanguageServerStart.java:71)
	at org.eclipse.osgi.internal.framework.BundleContextImpl$2.run(BundleContextImpl.java:818)
	at org.eclipse.osgi.internal.framework.BundleContextImpl$2.run(BundleContextImpl.java:1)
	at java.base/java.security.AccessController.doPrivileged(AccessController.java:569)
	at org.eclipse.osgi.internal.framework.BundleContextImpl.startActivator(BundleContextImpl.java:810)
	... 14 more
Caused by: org.xml.sax.SAXParseException; systemId: file:/C:/Users/myName/AppData/Roaming/Code/User/workspaceStorage/c2d6260b73da6e426b91d7bd9c5b1036/redhat.java/jdt_ws/.metadata/.plugins/org.eclipse.jdt.ls.logback/emptylogback.xml; lineNumber: 1; columnNumber: 1; Premature end of file.
	at java.xml/com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.parse(AbstractSAXParser.java:1251)
	at java.xml/com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl$JAXPSAXParser.parse(SAXParserImpl.java:637)
	at java.xml/com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl.parse(SAXParserImpl.java:326)
	at ch.qos.logback.core.joran.event.SaxEventRecorder.recordEvents(SaxEventRecorder.java:59)
	... 23 more
Root exception:
ch.qos.logback.core.joran.spi.JoranException: Problem parsing XML document. See previously reported errors.
	at ch.qos.logback.core.joran.event.SaxEventRecorder.recordEvents(SaxEventRecorder.java:65)
	at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:151)
	at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:110)
	at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:53)
	at org.eclipse.jdt.ls.logback.JavaLanguageServerStart.loadConfiguration(JavaLanguageServerStart.java:110)
	at org.eclipse.jdt.ls.logback.JavaLanguageServerStart.start(JavaLanguageServerStart.java:71)
	at org.eclipse.osgi.internal.framework.BundleContextImpl$2.run(BundleContextImpl.java:818)
	at org.eclipse.osgi.internal.framework.BundleContextImpl$2.run(BundleContextImpl.java:1)
	at java.base/java.security.AccessController.doPrivileged(AccessController.java:569)
	at org.eclipse.osgi.internal.framework.BundleContextImpl.startActivator(BundleContextImpl.java:810)
	at org.eclipse.osgi.internal.framework.BundleContextImpl.start(BundleContextImpl.java:767)
	at org.eclipse.osgi.internal.framework.EquinoxBundle.startWorker0(EquinoxBundle.java:1032)
	at org.eclipse.osgi.internal.framework.EquinoxBundle$EquinoxModule.startWorker(EquinoxBundle.java:371)
	at org.eclipse.osgi.container.Module.doStart(Module.java:605)
	at org.eclipse.osgi.container.Module.start(Module.java:468)
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel$2.run(ModuleContainer.java:1847)
	at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor$1$1.execute(EquinoxContainerAdaptor.java:136)
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1840)
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1783)
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1745)
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1667)
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1)
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:234)
	at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:345)
Caused by: org.xml.sax.SAXParseException; systemId: file:/C:/Users/myName/AppData/Roaming/Code/User/workspaceStorage/c2d6260b73da6e426b91d7bd9c5b1036/redhat.java/jdt_ws/.metadata/.plugins/org.eclipse.jdt.ls.logback/emptylogback.xml; lineNumber: 1; columnNumber: 1; Premature end of file.
	at java.xml/com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.parse(AbstractSAXParser.java:1251)
	at java.xml/com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl$JAXPSAXParser.parse(SAXParserImpl.java:637)
	at java.xml/com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl.parse(SAXParserImpl.java:326)
	at ch.qos.logback.core.joran.event.SaxEventRecorder.recordEvents(SaxEventRecorder.java:59)
	... 23 more

!ENTRY org.eclipse.osgi 4 0 2022-06-17 11:25:55.158
!MESSAGE Bundle org.eclipse.jdt.ls.logback_1.13.0.202206170301 [54] is not active.

@snjeza
Copy link
Contributor Author

snjeza commented Jun 17, 2022

@testforstephen I can reproduce the issue on Windows. I have fixed it. Could you, please, try again.

@testforstephen
Copy link
Contributor

With the latest changes, I didn't see the exception above. But I found another issue. When I removed -Djdt.ls.debug=true from java.jdt.ls.vmargs, it still printed verbose m2e log to the .log file.

@snjeza
Copy link
Contributor Author

snjeza commented Jun 17, 2022

With the latest changes, I didn't see the exception above. But I found another issue. When I removed -Djdt.ls.debug=true from java.jdt.ls.vmargs, it still printed verbose m2e log to the .log file.

@testforstephen I can't reproduce the issue. Could you attach your server log?

@testforstephen
Copy link
Contributor

With the latest changes, I didn't see the exception above. But I found another issue. When I removed -Djdt.ls.debug=true from java.jdt.ls.vmargs, it still printed verbose m2e log to the .log file.

@testforstephen I can't reproduce the issue. Could you attach your server log?

It turns out I have enabled jdt.ls.debug somewhere. After I cleaned it, no m2e log is printed to .log file.

@snjeza
Copy link
Contributor Author

snjeza commented Jun 18, 2022

@rgrunber
Copy link
Contributor

I think with jdt.ls.start gone, and just introducing a 1 or 2 logback deps and our own fragment host is pretty reasonable to get the logging into the server logs. If @testforstephen's issue is gone I think we can merge this!

Bundle-Version: 1.13.0.qualifier
Fragment-Host: ch.qos.logback.classic
Automatic-Module-Name: org.eclipse.jdt.ls.logback.appender
Bundle-RequiredExecutionEnvironment: JavaSE-11
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

it should be JavaSE-17

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Fixed.

Copy link
Contributor

@testforstephen testforstephen left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The latest change works well for me.

Signed-off-by: Snjezana Peco <snjezana.peco@redhat.com>
@snjeza snjeza merged commit d1779cd into eclipse-jdtls:master Jun 22, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Add logback tracing to Java LS
3 participants