which versions are you using (SonarQube, Scanner, Plugin, and any relevant extension)
Coming from SonarQube 9.9.2 to 10.2.1 on CentOS 8, with Java 17 and JAVA_HOME is set correctly
how is SonarQube deployed: zip, Docker, Helm:
Zip
SonarQube works just fine with 9.9.2 and has no issues. We are trying to update to 10.2.1. When trying to start the server with ./sonar.sh start, the service will start. But when it tries to start Elasticsearch, if fails because it is looking for tools.jar in Java 11 for some reason (which does not exist). Elasticsearch is also started with Java 17 so I am not sure why it is even searching in a Java 11 directory. Below are the nohup.log, sonar.log, and es.log files.
nohup.log:
2023.10.26 15:40:05 INFO app[][o.s.a.AppFileSystem] Cleaning or creating temp directory /home/sonarqube/sonarqube-10.2.1.78527/temp
2023.10.26 15:40:05 INFO app[][o.s.a.es.EsSettings] Elasticsearch listening on [HTTP: 127.0.0.1:9001, TCP: 127.0.0.1:37719]
2023.10.26 15:40:05 INFO app[][o.s.a.ProcessLauncherImpl] Launch process[ELASTICSEARCH] from [/home/sonarqube/sonarqube-10.2.1.78527/elasticsearch]: /usr/local/jdk-17.0.6+10/bin/java -Xms4m -Xmx64m -XX:+UseSerialGC -Dcli.name=server -Dcli.script=./bin/elasticsearch -Dcli.libs=lib/tools/server-cli -Des.path.home=/home/sonarqube/sonarqube-10.2.1.78527/elasticsearch -Des.path.conf=/home/sonarqube/sonarqube-10.2.1.78527/temp/conf/es -Des.distribution.type=tar -cp /home/sonarqube/sonarqube-10.2.1.78527/elasticsearch/lib/*:/home/sonarqube/sonarqube-10.2.1.78527/elasticsearch/lib/cli-launcher/* org.elasticsearch.launcher.CliToolLauncher
2023.10.26 15:40:05 INFO app[][o.s.a.SchedulerImpl] Waiting for Elasticsearch to be up and running
ERROR: Elasticsearch did not exit normally - check the logs at /home/sonarqube/sonarqube-10.2.1.78527/logs/sonarqube.log
ERROR: Elasticsearch exited unexpectedly
2023.10.26 15:40:09 WARN app[][o.s.a.p.AbstractManagedProcess] Process exited with exit value [ElasticSearch]: 1
2023.10.26 15:40:09 INFO app[][o.s.a.SchedulerImpl] Process[ElasticSearch] is stopped
2023.10.26 15:40:09 INFO app[][o.s.a.SchedulerImpl] SonarQube is stopped
es.log:
2023.10.26 15:40:09 ERROR es[][o.e.b.Elasticsearch] fatal exception while booting Elasticsearch
java.nio.file.NoSuchFileException: /usr/lib/jvm/java-11-openjdk-11.0.9.11-0.el8_2.x86_64/lib/tools.jar
at sun.nio.fs.UnixException.translateToIOException(UnixException.java:92) ~[?:?]
at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:106) ~[?:?]
at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:111) ~[?:?]
at sun.nio.fs.UnixFileAttributeViews$Basic.readAttributes(UnixFileAttributeViews.java:55) ~[?:?]
at sun.nio.fs.UnixFileSystemProvider.readAttributes(UnixFileSystemProvider.java:148) ~[?:?]
at sun.nio.fs.LinuxFileSystemProvider.readAttributes(LinuxFileSystemProvider.java:99) ~[?:?]
at java.nio.file.Files.readAttributes(Files.java:1851) ~[?:?]
at java.util.zip.ZipFile$Source.get(ZipFile.java:1264) ~[?:?]
at java.util.zip.ZipFile$CleanableResource.<init>(ZipFile.java:709) ~[?:?]
at java.util.zip.ZipFile.<init>(ZipFile.java:243) ~[?:?]
at java.util.zip.ZipFile.<init>(ZipFile.java:172) ~[?:?]
at java.util.jar.JarFile.<init>(JarFile.java:347) ~[?:?]
at java.util.jar.JarFile.<init>(JarFile.java:318) ~[?:?]
at java.util.jar.JarFile.<init>(JarFile.java:257) ~[?:?]
at org.elasticsearch.jdk.JarHell.checkJarHell(JarHell.java:221) ~[elasticsearch-core-8.7.0.jar:?]
at org.elasticsearch.jdk.JarHell.checkJarHell(JarHell.java:84) ~[elasticsearch-core-8.7.0.jar:?]
at org.elasticsearch.bootstrap.Elasticsearch.initPhase2(Elasticsearch.java:175) ~[elasticsearch-8.7.0.jar:?]
at org.elasticsearch.bootstrap.Elasticsearch.main(Elasticsearch.java:66) ~[elasticsearch-8.7.0.jar:?]
sonar.log:
2023.10.26 15:40:05 INFO app[][o.s.a.AppFileSystem] Cleaning or creating temp directory /home/sonarqube/sonarqube-10.2.1.78527/temp
2023.10.26 15:40:05 INFO app[][o.s.a.es.EsSettings] Elasticsearch listening on [HTTP: 127.0.0.1:9001, TCP: 127.0.0.1:37719]
2023.10.26 15:40:05 INFO app[][o.s.a.ProcessLauncherImpl] Launch process[ELASTICSEARCH] from [/home/sonarqube/sonarqube-10.2.1.78527/elasticsearch]: /usr/local/jdk-17.0.6+10/bin/java -Xms4m -Xmx64m -XX:+UseSerialGC -Dcli.name=server -Dcli.script=./bin/elasticsearch -Dcli.libs=lib/tools/server-cli -Des.path.home=/home/sonarqube/sonarqube-10.2.1.78527/elasticsearch -Des.path.conf=/home/sonarqube/sonarqube-10.2.1.78527/temp/conf/es -Des.distribution.type=tar -cp /home/sonarqube/sonarqube-10.2.1.78527/elasticsearch/lib/*:/home/sonarqube/sonarqube-10.2.1.78527/elasticsearch/lib/cli-launcher/* org.elasticsearch.launcher.CliToolLauncher
2023.10.26 15:40:05 INFO app[][o.s.a.SchedulerImpl] Waiting for Elasticsearch to be up and running
2023.10.26 15:40:09 WARN app[][o.s.a.p.AbstractManagedProcess] Process exited with exit value [ElasticSearch]: 1
2023.10.26 15:40:09 INFO app[][o.s.a.SchedulerImpl] Process[ElasticSearch] is stopped
2023.10.26 15:40:09 INFO app[][o.s.a.SchedulerImpl] SonarQube is stopped
I am honestly pretty new to SonarQube all together, but I upgraded us from 9.9.0 to 9.9.2 with no issues. But this is a bit beyond what I know how to fix. Any and all help is greatly appreciated.
Tools.jar isn’t actually a part of Java 11jdk, so why is it even looking for that in the first place?
Again, I am pretty new to SonarQube, but why would 9.9.2 start correctly, but 10.2.1 fail when using the same version of Java?
Which server logs are you referring to?
Again, thanks for you your help. It is very much appreciated.
JAVA_HOME is set to to our Java 17 path /usr/local/jdk-17.0.6+10. You can see below that we are indeed using Java 17.
[sonarqube@sonarqube ~]$ java -version
openjdk version "17.0.6" 2023-01-17
OpenJDK Runtime Environment Temurin-17.0.6+10 (build 17.0.6+10)
OpenJDK 64-Bit Server VM Temurin-17.0.6+10 (build 17.0.6+10, mixed mode, sharing)
This is why I am confused about 10.2.1 referring to Java 11 at all. And even then, tools.jar which has never been a thing in Java 11.
I’m posting the full logs, but they show nothing different, only the same thing three times in a row from trying to do this 3 times. nohup.log only shows the last startup so the full log is in my first post. I also have no web log since the server never actually gets started.
es.log
2023.10.26 14:48:36 ERROR es[][o.e.b.Elasticsearch] fatal exception while booting Elasticsearch
java.nio.file.NoSuchFileException: /usr/lib/jvm/java-11-openjdk-11.0.9.11-0.el8_2.x86_64/lib/tools.jar
at sun.nio.fs.UnixException.translateToIOException(UnixException.java:92) ~[?:?]
at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:106) ~[?:?]
at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:111) ~[?:?]
at sun.nio.fs.UnixFileAttributeViews$Basic.readAttributes(UnixFileAttributeViews.java:55) ~[?:?]
at sun.nio.fs.UnixFileSystemProvider.readAttributes(UnixFileSystemProvider.java:148) ~[?:?]
at sun.nio.fs.LinuxFileSystemProvider.readAttributes(LinuxFileSystemProvider.java:99) ~[?:?]
at java.nio.file.Files.readAttributes(Files.java:1851) ~[?:?]
at java.util.zip.ZipFile$Source.get(ZipFile.java:1264) ~[?:?]
at java.util.zip.ZipFile$CleanableResource.<init>(ZipFile.java:709) ~[?:?]
at java.util.zip.ZipFile.<init>(ZipFile.java:243) ~[?:?]
at java.util.zip.ZipFile.<init>(ZipFile.java:172) ~[?:?]
at java.util.jar.JarFile.<init>(JarFile.java:347) ~[?:?]
at java.util.jar.JarFile.<init>(JarFile.java:318) ~[?:?]
at java.util.jar.JarFile.<init>(JarFile.java:257) ~[?:?]
at org.elasticsearch.jdk.JarHell.checkJarHell(JarHell.java:221) ~[elasticsearch-core-8.7.0.jar:?]
at org.elasticsearch.jdk.JarHell.checkJarHell(JarHell.java:84) ~[elasticsearch-core-8.7.0.jar:?]
at org.elasticsearch.bootstrap.Elasticsearch.initPhase2(Elasticsearch.java:175) ~[elasticsearch-8.7.0.jar:?]
at org.elasticsearch.bootstrap.Elasticsearch.main(Elasticsearch.java:66) ~[elasticsearch-8.7.0.jar:?]
2023.10.26 15:05:04 ERROR es[][o.e.b.Elasticsearch] fatal exception while booting Elasticsearch
java.nio.file.NoSuchFileException: /usr/lib/jvm/java-11-openjdk-11.0.9.11-0.el8_2.x86_64/lib/tools.jar
at sun.nio.fs.UnixException.translateToIOException(UnixException.java:92) ~[?:?]
at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:106) ~[?:?]
at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:111) ~[?:?]
at sun.nio.fs.UnixFileAttributeViews$Basic.readAttributes(UnixFileAttributeViews.java:55) ~[?:?]
at sun.nio.fs.UnixFileSystemProvider.readAttributes(UnixFileSystemProvider.java:148) ~[?:?]
at sun.nio.fs.LinuxFileSystemProvider.readAttributes(LinuxFileSystemProvider.java:99) ~[?:?]
at java.nio.file.Files.readAttributes(Files.java:1851) ~[?:?]
at java.util.zip.ZipFile$Source.get(ZipFile.java:1264) ~[?:?]
at java.util.zip.ZipFile$CleanableResource.<init>(ZipFile.java:709) ~[?:?]
at java.util.zip.ZipFile.<init>(ZipFile.java:243) ~[?:?]
at java.util.zip.ZipFile.<init>(ZipFile.java:172) ~[?:?]
at java.util.jar.JarFile.<init>(JarFile.java:347) ~[?:?]
at java.util.jar.JarFile.<init>(JarFile.java:318) ~[?:?]
at java.util.jar.JarFile.<init>(JarFile.java:257) ~[?:?]
at org.elasticsearch.jdk.JarHell.checkJarHell(JarHell.java:221) ~[elasticsearch-core-8.7.0.jar:?]
at org.elasticsearch.jdk.JarHell.checkJarHell(JarHell.java:84) ~[elasticsearch-core-8.7.0.jar:?]
at org.elasticsearch.bootstrap.Elasticsearch.initPhase2(Elasticsearch.java:175) ~[elasticsearch-8.7.0.jar:?]
at org.elasticsearch.bootstrap.Elasticsearch.main(Elasticsearch.java:66) ~[elasticsearch-8.7.0.jar:?]
2023.10.26 15:40:09 ERROR es[][o.e.b.Elasticsearch] fatal exception while booting Elasticsearch
java.nio.file.NoSuchFileException: /usr/lib/jvm/java-11-openjdk-11.0.9.11-0.el8_2.x86_64/lib/tools.jar
at sun.nio.fs.UnixException.translateToIOException(UnixException.java:92) ~[?:?]
at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:106) ~[?:?]
at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:111) ~[?:?]
at sun.nio.fs.UnixFileAttributeViews$Basic.readAttributes(UnixFileAttributeViews.java:55) ~[?:?]
at sun.nio.fs.UnixFileSystemProvider.readAttributes(UnixFileSystemProvider.java:148) ~[?:?]
at sun.nio.fs.LinuxFileSystemProvider.readAttributes(LinuxFileSystemProvider.java:99) ~[?:?]
at java.nio.file.Files.readAttributes(Files.java:1851) ~[?:?]
at java.util.zip.ZipFile$Source.get(ZipFile.java:1264) ~[?:?]
at java.util.zip.ZipFile$CleanableResource.<init>(ZipFile.java:709) ~[?:?]
at java.util.zip.ZipFile.<init>(ZipFile.java:243) ~[?:?]
at java.util.zip.ZipFile.<init>(ZipFile.java:172) ~[?:?]
at java.util.jar.JarFile.<init>(JarFile.java:347) ~[?:?]
at java.util.jar.JarFile.<init>(JarFile.java:318) ~[?:?]
at java.util.jar.JarFile.<init>(JarFile.java:257) ~[?:?]
at org.elasticsearch.jdk.JarHell.checkJarHell(JarHell.java:221) ~[elasticsearch-core-8.7.0.jar:?]
at org.elasticsearch.jdk.JarHell.checkJarHell(JarHell.java:84) ~[elasticsearch-core-8.7.0.jar:?]
at org.elasticsearch.bootstrap.Elasticsearch.initPhase2(Elasticsearch.java:175) ~[elasticsearch-8.7.0.jar:?]
at org.elasticsearch.bootstrap.Elasticsearch.main(Elasticsearch.java:66) ~[elasticsearch-8.7.0.jar:?]
sonar.log
2023.10.26 14:48:29 INFO app[][o.s.a.AppFileSystem] Cleaning or creating temp directory /home/sonarqube/sonarqube-10.2.1.78527/temp
2023.10.26 14:48:29 INFO app[][o.s.a.es.EsSettings] Elasticsearch listening on [HTTP: 127.0.0.1:9001, TCP: 127.0.0.1:43347]
2023.10.26 14:48:29 INFO app[][o.s.a.ProcessLauncherImpl] Launch process[ELASTICSEARCH] from [/home/sonarqube/sonarqube-10.2.1.78527/elasticsearch]: /usr/local/jdk-17.0.6+10/bin/java -Xms4m -Xmx64m -XX:+UseSerialGC -Dcli.name=server -Dcli.script=./bin/elasticsearch -Dcli.libs=lib/tools/server-cli -Des.path.home=/home/sonarqube/sonarqube-10.2.1.78527/elasticsearch -Des.path.conf=/home/sonarqube/sonarqube-10.2.1.78527/temp/conf/es -Des.distribution.type=tar -cp /home/sonarqube/sonarqube-10.2.1.78527/elasticsearch/lib/*:/home/sonarqube/sonarqube-10.2.1.78527/elasticsearch/lib/cli-launcher/* org.elasticsearch.launcher.CliToolLauncher
2023.10.26 14:48:29 INFO app[][o.s.a.SchedulerImpl] Waiting for Elasticsearch to be up and running
2023.10.26 14:48:36 WARN app[][o.s.a.p.AbstractManagedProcess] Process exited with exit value [ElasticSearch]: 1
2023.10.26 14:48:36 INFO app[][o.s.a.SchedulerImpl] Process[ElasticSearch] is stopped
2023.10.26 14:48:36 INFO app[][o.s.a.SchedulerImpl] SonarQube is stopped
2023.10.26 15:05:00 INFO app[][o.s.a.AppFileSystem] Cleaning or creating temp directory /home/sonarqube/sonarqube-10.2.1.78527/temp
2023.10.26 15:05:00 INFO app[][o.s.a.es.EsSettings] Elasticsearch listening on [HTTP: 127.0.0.1:9001, TCP: 127.0.0.1:43993]
2023.10.26 15:05:00 INFO app[][o.s.a.ProcessLauncherImpl] Launch process[ELASTICSEARCH] from [/home/sonarqube/sonarqube-10.2.1.78527/elasticsearch]: /usr/local/jdk-17.0.6+10/bin/java -Xms4m -Xmx64m -XX:+UseSerialGC -Dcli.name=server -Dcli.script=./bin/elasticsearch -Dcli.libs=lib/tools/server-cli -Des.path.home=/home/sonarqube/sonarqube-10.2.1.78527/elasticsearch -Des.path.conf=/home/sonarqube/sonarqube-10.2.1.78527/temp/conf/es -Des.distribution.type=tar -cp /home/sonarqube/sonarqube-10.2.1.78527/elasticsearch/lib/*:/home/sonarqube/sonarqube-10.2.1.78527/elasticsearch/lib/cli-launcher/* org.elasticsearch.launcher.CliToolLauncher
2023.10.26 15:05:00 INFO app[][o.s.a.SchedulerImpl] Waiting for Elasticsearch to be up and running
2023.10.26 15:05:04 WARN app[][o.s.a.p.AbstractManagedProcess] Process exited with exit value [ElasticSearch]: 1
2023.10.26 15:05:04 INFO app[][o.s.a.SchedulerImpl] Process[ElasticSearch] is stopped
2023.10.26 15:05:04 INFO app[][o.s.a.SchedulerImpl] SonarQube is stopped
2023.10.26 15:40:05 INFO app[][o.s.a.AppFileSystem] Cleaning or creating temp directory /home/sonarqube/sonarqube-10.2.1.78527/temp
2023.10.26 15:40:05 INFO app[][o.s.a.es.EsSettings] Elasticsearch listening on [HTTP: 127.0.0.1:9001, TCP: 127.0.0.1:37719]
2023.10.26 15:40:05 INFO app[][o.s.a.ProcessLauncherImpl] Launch process[ELASTICSEARCH] from [/home/sonarqube/sonarqube-10.2.1.78527/elasticsearch]: /usr/local/jdk-17.0.6+10/bin/java -Xms4m -Xmx64m -XX:+UseSerialGC -Dcli.name=server -Dcli.script=./bin/elasticsearch -Dcli.libs=lib/tools/server-cli -Des.path.home=/home/sonarqube/sonarqube-10.2.1.78527/elasticsearch -Des.path.conf=/home/sonarqube/sonarqube-10.2.1.78527/temp/conf/es -Des.distribution.type=tar -cp /home/sonarqube/sonarqube-10.2.1.78527/elasticsearch/lib/*:/home/sonarqube/sonarqube-10.2.1.78527/elasticsearch/lib/cli-launcher/* org.elasticsearch.launcher.CliToolLauncher
2023.10.26 15:40:05 INFO app[][o.s.a.SchedulerImpl] Waiting for Elasticsearch to be up and running
2023.10.26 15:40:09 WARN app[][o.s.a.p.AbstractManagedProcess] Process exited with exit value [ElasticSearch]: 1
2023.10.26 15:40:09 INFO app[][o.s.a.SchedulerImpl] Process[ElasticSearch] is stopped
2023.10.26 15:40:09 INFO app[][o.s.a.SchedulerImpl] SonarQube is stopped
Again, thank you for all your help! It is greatly appreciated.
Those are the only logs I have. There are no other logs. If you are looking for another log, can you please be more specific about which logs and where to find them? I’ve uploaded the logs this time instead of copied them inline, and I have uploaded a screenshot to show there are no more logs in the log folder.
On the environment where SonarQube is running (I deducted it was Linux), could you please check if the following environment variable has some values? echo $LD_LIBRARY_PATH
No it is not supposed to be set, but from your logs, it seems that there is something in your system that implicitly adds some libraries to the classpath of java. (and namely, the /usr/lib/jvm/java-11-openjdk-11.0.9.11-0.el8_2.x86_64/lib/tools.jar file which is absent on your system)
Indeed, the JarHell component of ElasticSearch (where the issue occurs) is scanning the classpath in search of duplicate classes, but fails because it cannot find one jar that is in the classpath (tools.jar).
My assumption was you had something specified in $LD_LIBRARY_PATH, which is a way to add arbitrary jar files to the java classpath.
Could you try to execute SonarQube in debug mode, by adding sonar.log.level=DEBUG in sonar.properties file, and post the log files here? It should give more information on where this /usr/lib/jvm/java-11-openjdk-11.0.9.11-0.el8_2.x86_64/lib/tools.jar file comes from
Also, are you sure that file /usr/lib/jvm/java-11-openjdk-11.0.9.11-0.el8_2.x86_64/lib/tools.jar doesn’t exist in your system? Could it be that the user executing sonarqube has no permission to this file?
Since the logs are now quite a bit longer, I am going to attach them instead of pasting them as text. Here are the logs after I tried starting with DEBUG logging. Hopefully this helps. es.log (12.2 KB) nohup.log (147.4 KB) sonar.log (154.7 KB)
There is indeed something on your system that is polluting the java class path, with what I believe is some paths from your old java 11 binaries that have been removed.
You need to identify what is causing that on your system and make the changes so those old paths are not added to the java classpath anymore (you can start by checking the CLASSPATH env variable: echo $CLASSPATH)
I’m not sure what the classpath should be or if it is actually needed. I also find it odd, that this still works with sonarqube 9.9.x (both 9.9.0 and 9.9.2) and only started doing this when moving to sonarqube 10.2.1. Do you know why this would be?
I removed the classpath environment variable and I was able to get SonarQube 10.2.1 up. Thanks so much. But also, if that needs to be there or replaced for any reason, please let me know.
Whether you need the classpath to be set or not is very specific to your distribution, and the way Java is installed on your system.
Regarding why it was not happening in 9.9.2: we update ElasticSearch regularly along with SonarQube, so it is most likely that the check causing the error has been introduced in the latest version of ElasticSearch