[Bug 270855] devel/sonarqube-community: does not start anymore

From: <bugzilla-noreply_at_freebsd.org>
Date: Sat, 15 Apr 2023 06:25:52 UTC
https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=270855

            Bug ID: 270855
           Summary: devel/sonarqube-community: does not start anymore
           Product: Ports & Packages
           Version: Latest
          Hardware: Any
                OS: Any
            Status: New
          Severity: Affects Only Me
          Priority: ---
         Component: Individual Port(s)
          Assignee: netchild@FreeBSD.org
          Reporter: mfechner@FreeBSD.org
             Flags: maintainer-feedback?(netchild@FreeBSD.org)
          Assignee: netchild@FreeBSD.org

I upgraded to version sonarqube-community-10.0.0.68432 and upgraded the
configfile as mentioned in UPDATING 20230407:
sonar.search.javaAdditionalOpts=-server

But it does not start.

If I check the logs I do not find anything helpful.
```
2023.04.15 09:13:06 INFO  app[][o.s.a.AppFileSystem] Cleaning or creating temp
directory /var/db/sonarqube/temp
2023.04.15 09:13:06 INFO  app[][o.s.a.es.EsSettings] Elasticsearch listening on
[HTTP: 127.0.0.1:9005, TCP: 127.0.0.1:17246]
2023.04.15 09:13:06 INFO  app[][o.s.a.ProcessLauncherImpl] Launch
process[ELASTICSEARCH] from [/usr/local/libexec/sonarqube/elasticsearch]:
/usr/local/openjdk17/bin/java -Xms4m -Xmx64m -XX:+UseSerialGC -Dcli.name=server
-Dcli.script=./bin/elasticsearch -Dcli.libs=lib/tools/server-cli
-Des.path.home=/usr/local/libexec/sonarqube/elasticsearch
-Des.path.conf=/var/db/sonarqube/temp/conf/es -Des.distribution.type=tar -cp
/usr/local/libexec/sonarqube/elasticsearch/lib/*:/usr/local/libexec/sonarqube/elasticsearch/lib/cli-launcher/*
org.elasticsearch.launcher.CliToolLauncher
2023.04.15 09:13:06 INFO  app[][o.s.a.SchedulerImpl] Waiting for Elasticsearch
to be up and running
Failed to load native library:jansi-2.4.0-c836b5eaa762e049-libjansi.so. osinfo:
FreeBSD/x86_64
java.lang.UnsatisfiedLinkError:
/var/db/sonarqube/temp/jansi-2.4.0-c836b5eaa762e049-libjansi.so:
/var/db/sonarqube/temp/jansi-2.4.0-c836b5eaa762e049-libjansi.so: mmap of data
failed: Permission denied
bootstrap check failure [1] of [1]: system call filters failed to install;
check the logs and fix your configuration
ERROR: Elasticsearch did not exit normally - check the logs at
/var/log/sonarqube/sonarqube.log

ERROR: [1] bootstrap checks failed. You must address the points described in
the following [1] lines before starting Elasticsearch.
2023.04.15 09:13:11 WARN  app[][o.s.a.p.AbstractManagedProcess] Process exited
with exit value [ElasticSearch]: 78
2023.04.15 09:13:11 INFO  app[][o.s.a.SchedulerImpl] Process[ElasticSearch] is
stopped
2023.04.15 09:13:11 ERROR app[][o.s.a.p.EsManagedProcess] Failed to check
status
org.elasticsearch.ElasticsearchException: java.lang.InterruptedException
        at
org.elasticsearch.client.RestHighLevelClient.performClientRequest(RestHighLevelClient.java:2695)
        at
org.elasticsearch.client.RestHighLevelClient.internalPerformRequest(RestHighLevelClient.java:2171)
        at
org.elasticsearch.client.RestHighLevelClient.performRequest(RestHighLevelClient.java:2137)
        at
org.elasticsearch.client.RestHighLevelClient.performRequestAndParseEntity(RestHighLevelClient.java:2105)
        at
org.elasticsearch.client.ClusterClient.health(ClusterClient.java:151)
        at
org.sonar.application.es.EsConnectorImpl.getClusterHealthStatus(EsConnectorImpl.java:64)
        at
org.sonar.application.process.EsManagedProcess.checkStatus(EsManagedProcess.java:92)
        at
org.sonar.application.process.EsManagedProcess.checkOperational(EsManagedProcess.java:84)
        at
org.sonar.application.process.EsManagedProcess.isOperational(EsManagedProcess.java:62)
        at
org.sonar.application.process.ManagedProcessHandler.refreshState(ManagedProcessHandler.java:223)
        at
org.sonar.application.process.ManagedProcessHandler$EventWatcher.run(ManagedProcessHandler.java:288)
Caused by: java.lang.InterruptedException: null
        at
java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1048)
        at
org.elasticsearch.common.util.concurrent.BaseFuture$Sync.get(BaseFuture.java:243)
        at
org.elasticsearch.common.util.concurrent.BaseFuture.get(BaseFuture.java:75)
        at
org.elasticsearch.client.RestHighLevelClient.performClientRequest(RestHighLevelClient.java:2692)
        ... 10 common frames omitted
2023.04.15 09:13:11 INFO  app[][o.s.a.SchedulerImpl] SonarQube is stopped
```

The sonar.log:
```
2023.04.15 09:13:06 INFO  app[][o.s.a.AppFileSystem] Cleaning or creating temp
directory /var/db/sonarqube/temp
2023.04.15 09:13:06 INFO  app[][o.s.a.es.EsSettings] Elasticsearch listening on
[HTTP: 127.0.0.1:9005, TCP: 127.0.0.1:17246]
2023.04.15 09:13:06 INFO  app[][o.s.a.ProcessLauncherImpl] Launch
process[ELASTICSEARCH] from [/usr/local/libexec/sonarqube/elasticsearch]:
/usr/local/openjdk17/bin/java -Xms4m -Xmx64m -XX:+UseSerialGC -Dcli.name=server
-Dcli.script=./bin/elasticsearch -Dcli.libs=lib/tools/server-cli
-Des.path.home=/usr/local/libexec/sonarqube/elasticsearch
-Des.path.conf=/var/db/sonarqube/temp/conf/es -Des.distribution.type=tar -cp
/usr/local/libexec/sonarqube/elasticsearch/lib/*:/usr/local/libexec/sonarqube/elasticsearch/lib/cli-launcher/*
org.elasticsearch.launcher.CliToolLauncher
2023.04.15 09:13:06 INFO  app[][o.s.a.SchedulerImpl] Waiting for Elasticsearch
to be up and running
2023.04.15 09:13:11 WARN  app[][o.s.a.p.AbstractManagedProcess] Process exited
with exit value [ElasticSearch]: 78
2023.04.15 09:13:11 INFO  app[][o.s.a.SchedulerImpl] Process[ElasticSearch] is
stopped
2023.04.15 09:13:11 ERROR app[][o.s.a.p.EsManagedProcess] Failed to check
status
org.elasticsearch.ElasticsearchException: java.lang.InterruptedException
        at
org.elasticsearch.client.RestHighLevelClient.performClientRequest(RestHighLevelClient.java:2695)
        at
org.elasticsearch.client.RestHighLevelClient.internalPerformRequest(RestHighLevelClient.java:2171)
        at
org.elasticsearch.client.RestHighLevelClient.performRequest(RestHighLevelClient.java:2137)
        at
org.elasticsearch.client.RestHighLevelClient.performRequestAndParseEntity(RestHighLevelClient.java:2105)
        at
org.elasticsearch.client.ClusterClient.health(ClusterClient.java:151)
        at
org.sonar.application.es.EsConnectorImpl.getClusterHealthStatus(EsConnectorImpl.java:64)
        at
org.sonar.application.process.EsManagedProcess.checkStatus(EsManagedProcess.java:92)
        at
org.sonar.application.process.EsManagedProcess.checkOperational(EsManagedProcess.java:84)
        at
org.sonar.application.process.EsManagedProcess.isOperational(EsManagedProcess.java:62)
        at
org.sonar.application.process.ManagedProcessHandler.refreshState(ManagedProcessHandler.java:223)
        at
org.sonar.application.process.ManagedProcessHandler$EventWatcher.run(ManagedProcessHandler.java:288)
Caused by: java.lang.InterruptedException: null
        at
java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1048)
        at
org.elasticsearch.common.util.concurrent.BaseFuture$Sync.get(BaseFuture.java:243)
        at
org.elasticsearch.common.util.concurrent.BaseFuture.get(BaseFuture.java:75)
        at
org.elasticsearch.client.RestHighLevelClient.performClientRequest(RestHighLevelClient.java:2692)
        ... 10 common frames omitted
2023.04.15 09:13:11 INFO  app[][o.s.a.SchedulerImpl] SonarQube is stopped
2023.04.15 09:13:12 INFO  app[][o.s.a.AppFileSystem] Cleaning or creating temp
directory /var/db/sonarqube/temp
2023.04.15 09:13:12 INFO  app[][o.s.a.es.EsSettings] Elasticsearch listening on
[HTTP: 127.0.0.1:9005, TCP: 127.0.0.1:17299]
2023.04.15 09:13:12 INFO  app[][o.s.a.ProcessLauncherImpl] Launch
process[ELASTICSEARCH] from [/usr/local/libexec/sonarqube/elasticsearch]:
/usr/local/openjdk17/bin/java -Xms4m -Xmx64m -XX:+UseSerialGC -Dcli.name=server
-Dcli.script=./bin/elasticsearch -Dcli.libs=lib/tools/server-cli
-Des.path.home=/usr/local/libexec/sonarqube/elasticsearch
-Des.path.conf=/var/db/sonarqube/temp/conf/es -Des.distribution.type=tar -cp
/usr/local/libexec/sonarqube/elasticsearch/lib/*:/usr/local/libexec/sonarqube/elasticsearch/lib/cli-launcher/*
org.elasticsearch.launcher.CliToolLauncher
2023.04.15 09:13:12 INFO  app[][o.s.a.SchedulerImpl] Waiting for Elasticsearch
to be up and running
2023.04.15 09:13:17 WARN  app[][o.s.a.p.AbstractManagedProcess] Process exited
with exit value [ElasticSearch]: 78
2023.04.15 09:13:17 INFO  app[][o.s.a.SchedulerImpl] Process[ElasticSearch] is
stopped
2023.04.15 09:13:17 INFO  app[][o.s.a.SchedulerImpl] SonarQube is stopped
```
es.log:
```
2023.04.15 09:13:14 WARN  es[][o.e.b.Natives] unable to load JNA native support
library, native methods will be disabled.
java.lang.UnsatisfiedLinkError:
/var/db/sonarqube/temp/jna2650993593490345002.tmp:
/var/db/sonarqube/temp/jna2650993593490345002.tmp: mmap of data failed:
Permission denied
        at jdk.internal.loader.NativeLibraries.load(Native Method) ~[?:?]
        at
jdk.internal.loader.NativeLibraries$NativeLibraryImpl.open(NativeLibraries.java:388)
~[?:?]
        at
jdk.internal.loader.NativeLibraries.loadLibrary(NativeLibraries.java:232)
~[?:?]
        at
jdk.internal.loader.NativeLibraries.loadLibrary(NativeLibraries.java:174)
~[?:?]
        at java.lang.ClassLoader.loadLibrary(ClassLoader.java:2389) ~[?:?]
        at java.lang.Runtime.load0(Runtime.java:755) ~[?:?]
        at java.lang.System.load(System.java:1953) ~[?:?]
        at
com.sun.jna.Native.loadNativeDispatchLibraryFromClasspath(Native.java:1045)
~[jna-5.10.0.jar:?]
        at com.sun.jna.Native.loadNativeDispatchLibrary(Native.java:1015)
~[jna-5.10.0.jar:?]
        at com.sun.jna.Native.<clinit>(Native.java:221) ~[jna-5.10.0.jar:?]
        at java.lang.Class.forName0(Native Method) ~[?:?]
        at java.lang.Class.forName(Class.java:375) ~[?:?]
        at org.elasticsearch.bootstrap.Natives.<clinit>(Natives.java:34)
~[elasticsearch-8.6.1.jar:?]
        at
org.elasticsearch.bootstrap.Elasticsearch.initializeNatives(Elasticsearch.java:259)
~[elasticsearch-8.6.1.jar:?]
        at
org.elasticsearch.bootstrap.Elasticsearch.initPhase2(Elasticsearch.java:166)
~[elasticsearch-8.6.1.jar:?]
        at
org.elasticsearch.bootstrap.Elasticsearch.main(Elasticsearch.java:66)
~[elasticsearch-8.6.1.jar:?]
2023.04.15 09:13:14 WARN  es[][o.e.b.Natives] cannot check if running as root
because JNA is not available
2023.04.15 09:13:14 WARN  es[][o.e.b.Natives] cannot install system call filter
because JNA is not available
2023.04.15 09:13:14 WARN  es[][o.e.b.Natives] cannot register console handler
because JNA is not available
2023.04.15 09:13:14 WARN  es[][o.e.b.Natives] cannot getrlimit RLIMIT_NPROC
because JNA is not available
2023.04.15 09:13:14 WARN  es[][o.e.b.Natives] cannot getrlimit RLIMIT_AS
because JNA is not available
2023.04.15 09:13:14 WARN  es[][o.e.b.Natives] cannot getrlimit RLIMIT_FSIZE
because JNA is not available
2023.04.15 09:13:14 WARN  es[][o.e.c.f.FileSystemNatives] unable to load JNA
native support library, FileSystemNatives methods will be disabled.
java.lang.NoClassDefFoundError: Could not initialize class com.sun.jna.Native
        at java.lang.Class.forName0(Native Method) ~[?:?]
        at java.lang.Class.forName(Class.java:375) ~[?:?]
        at
org.elasticsearch.common.filesystem.FileSystemNatives.loadJnaProvider(FileSystemNatives.java:37)
~[elasticsearch-8.6.1.jar:?]
        at
org.elasticsearch.common.filesystem.FileSystemNatives.<clinit>(FileSystemNatives.java:31)
~[elasticsearch-8.6.1.jar:?]
        at
org.elasticsearch.bootstrap.Elasticsearch.initializeNatives(Elasticsearch.java:311)
~[elasticsearch-8.6.1.jar:?]
        at
org.elasticsearch.bootstrap.Elasticsearch.initPhase2(Elasticsearch.java:166)
~[elasticsearch-8.6.1.jar:?]
        at
org.elasticsearch.bootstrap.Elasticsearch.main(Elasticsearch.java:66)
~[elasticsearch-8.6.1.jar:?]
2023.04.15 09:13:14 INFO  es[][o.e.n.Node] version[8.6.1], pid[46098],
build[tar/180c9830da956993e59e2cd70eb32b5e383ea42c/2023-01-24T21:35:11.506992272Z],
OS[FreeBSD/13.1-RELEASE-p6/amd64], JVM[OpenJDK BSD Porting Team/OpenJDK 64-Bit
Server VM/17.0.6/17.0.6+10-1]
2023.04.15 09:13:14 INFO  es[][o.e.n.Node] JVM home [/usr/local/openjdk17],
using bundled JDK [false]
2023.04.15 09:13:14 INFO  es[][o.e.n.Node] JVM arguments
[-Des.networkaddress.cache.ttl=60, -Des.networkaddress.cache.negative.ttl=10,
-Djava.security.manager=allow, -XX:+AlwaysPreTouch, -Xss1m,
-Djava.awt.headless=true, -Dfile.encoding=UTF-8, -Djna.nosys=true,
-XX:-OmitStackTraceInFastThrow, -Dio.netty.noUnsafe=true,
-Dio.netty.noKeySetOptimization=true,
-Dio.netty.recycler.maxCapacityPerThread=0, -Dlog4j.shutdownHookEnabled=false,
-Dlog4j2.disable.jmx=true, -Dlog4j2.formatMsgNoLookups=true,
-Djava.locale.providers=SPI,COMPAT, --add-opens=java.base/java.io=ALL-UNNAMED,
-XX:+UseG1GC, -Djava.io.tmpdir=/var/db/sonarqube/temp,
-XX:ErrorFile=/var/log/sonarqube/es_hs_err_pid%p.log, -Xlog:disable,
-Des.networkaddress.cache.ttl=60, -Des.networkaddress.cache.negative.ttl=10,
-XX:+AlwaysPreTouch, -Xss1m, -Djava.awt.headless=true, -Dfile.encoding=UTF-8,
-Djna.nosys=true, -Djna.tmpdir=/var/db/sonarqube/temp,
-XX:-OmitStackTraceInFastThrow, -Dio.netty.noUnsafe=true,
-Dio.netty.noKeySetOptimization=true,
-Dio.netty.recycler.maxCapacityPerThread=0,
-Dio.netty.allocator.numDirectArenas=0, -Dlog4j.shutdownHookEnabled=false,
-Dlog4j2.disable.jmx=true, -Dlog4j2.formatMsgNoLookups=true,
-Djava.locale.providers=COMPAT, -Dcom.redhat.fips=false,
-Des.enforce.bootstrap.checks=true, -Xmx512m, -Xms512m,
-XX:MaxDirectMemorySize=256m, -XX:+HeapDumpOnOutOfMemoryError,
-XX:G1HeapRegionSize=4m, -XX:InitiatingHeapOccupancyPercent=30,
-XX:G1ReservePercent=15, -Des.distribution.type=tar,
--module-path=/usr/local/libexec/sonarqube/elasticsearch/lib,
--add-modules=jdk.net, -Djdk.module.main=org.elasticsearch.server]
2023.04.15 09:13:15 INFO  es[][o.e.p.PluginsService] loaded module
[aggregations]
2023.04.15 09:13:15 INFO  es[][o.e.p.PluginsService] loaded module
[analysis-common]
2023.04.15 09:13:15 INFO  es[][o.e.p.PluginsService] loaded module [apm]
2023.04.15 09:13:15 INFO  es[][o.e.p.PluginsService] loaded module
[lang-painless]
2023.04.15 09:13:15 INFO  es[][o.e.p.PluginsService] loaded module
[old-lucene-versions]
2023.04.15 09:13:15 INFO  es[][o.e.p.PluginsService] loaded module
[parent-join]
2023.04.15 09:13:15 INFO  es[][o.e.p.PluginsService] loaded module [reindex]
2023.04.15 09:13:15 INFO  es[][o.e.p.PluginsService] loaded module
[transport-netty4]
2023.04.15 09:13:15 INFO  es[][o.e.p.PluginsService] loaded module
[x-pack-aggregate-metric]
2023.04.15 09:13:15 INFO  es[][o.e.p.PluginsService] loaded module
[x-pack-core]
2023.04.15 09:13:15 INFO  es[][o.e.p.PluginsService] loaded module
[x-pack-security]
2023.04.15 09:13:15 INFO  es[][o.e.p.PluginsService] no plugins loaded
2023.04.15 09:13:16 INFO  es[][o.e.e.NodeEnvironment] using [1] data paths,
mounts [[/var/db (zroot/var/db)]], net usable_space [8tb], net total_space
[8tb], types [zfs]
2023.04.15 09:13:16 INFO  es[][o.e.e.NodeEnvironment] heap size [512mb],
compressed ordinary object pointers [true]
2023.04.15 09:13:16 INFO  es[][o.e.n.Node] node name [sonarqube], node ID
[Em3uATWYQEiZY_oGgEvLvA], cluster name [sonarqube], roles [data_frozen, ingest,
data_cold, data, remote_cluster_client, master, data_warm, data_content,
transform, data_hot, ml]
2023.04.15 09:13:16 INFO  es[][o.e.x.s.Security] Security is disabled
2023.04.15 09:13:16 INFO  es[][o.e.t.n.NettyAllocator] creating NettyAllocator
with the following configs: [name=unpooled, suggested_max_allocation_size=1mb,
factors={es.unsafe.use_unpooled_allocator=null, g1gc_enabled=true,
g1gc_region_size=4mb, heap_size=512mb}]
2023.04.15 09:13:16 INFO  es[][o.e.i.r.RecoverySettings] using rate limit
[40mb] with [default=40mb, read=0b, write=0b, max=0b]
2023.04.15 09:13:16 INFO  es[][o.e.d.DiscoveryModule] using discovery type
[single-node] and seed hosts providers [settings]
2023.04.15 09:13:17 INFO  es[][o.e.n.Node] initialized
2023.04.15 09:13:17 INFO  es[][o.e.n.Node] starting ...
2023.04.15 09:13:17 INFO  es[][o.e.t.TransportService] publish_address
{127.0.0.1:17299}, bound_addresses {127.0.0.1:17299}
2023.04.15 09:13:17 INFO  es[][o.e.b.BootstrapChecks] explicitly enforcing
bootstrap checks
2023.04.15 09:13:17 INFO  es[][o.e.n.Node] stopping ...
2023.04.15 09:13:17 INFO  es[][o.e.n.Node] stopped
2023.04.15 09:13:17 INFO  es[][o.e.n.Node] closing ...
2023.04.15 09:13:17 INFO  es[][o.e.n.Node] closed
```

I checked also the permission of the folder and it locks fine:
```
root@server:/var/log/sonarqube # ls -las /var/db/sonarqube/
total 20
 1 drwxr-xr-x   4 sonarqube  sonarqube   4 May  5  2020 .
17 drwxr-xr-x  44 root       wheel      59 Apr  6 21:16 ..
 1 drwxr-xr-x   4 sonarqube  sonarqube   4 Apr 15 08:18 data
 1 drwxr-xr-x   3 sonarqube  sonarqube   4 Apr 15 09:13 temp

root@server:/var/log/sonarqube # ls -las /var/db/sonarqube/temp
total 12
1 drwxr-xr-x  3 sonarqube  sonarqube     4 Apr 15 09:13 .
1 drwxr-xr-x  4 sonarqube  sonarqube     4 May  5  2020 ..
1 drwxr-xr-x  3 sonarqube  sonarqube     3 Apr 15 09:13 conf
9 -rw-r--r--  1 sonarqube  sonarqube  2565 Apr 15 09:13 sharedmemory

```

Do you have an idea what can cause this problem?

-- 
You are receiving this mail because:
You are the assignee for the bug.