Startup fails after Web Service attempt

MTSteve · February 10, 2022, 7:26pm

First off, I am attempting to upgrade an OLD database from v5-ish to 9.3. I’ve already upgraded 5.6.7 LTS, and I am currently on the 6.7.7 LTS version as its my understanding I need to do them incrementally (when I tried to jump versions I got LTS errors).

Like mentioned I did 5.6.7, and now that I am upgrading to 6.7.7, I’ve cleared up all errors except a weird one hanging out on the sonar.log just after the web application tries to launch. ES starts up just fine, and I’ll include that es.log at the very bottom, but in the sonar.log web process stops right after the web process launch is requested, so something is wrong with the way it is being requested. Also, no log entry is created for web.log. Here is a snippet of the section I am talking about followed by the complete log:

2022.02.10 10:04:59 INFO  app[][o.s.a.SchedulerImpl] Process[es] is up
2022.02.10 10:04:59 INFO  app[][o.s.a.p.ProcessLauncherImpl] Launch process[[key='web', ipcIndex=2, logFilenamePrefix=web]] from [  ]: /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.322.b06-2.el8_5.x86_64/jre/bin/java -Djava.awt.headless=true -Dfile.encoding=UTF-8 -Djava.io.tmpdir=/home/sonarqube/sonarqube-6.7.7/temp -Xmx512m -Xms128m -XX:+HeapDumpOnOutOfMemoryError -cp ./lib/common/*:./lib/server/*:/home/sonarqube/sonarqube-6.7.7/extensions/jdbc-driver/oracle/ojdbc7.jar org.sonar.server.app.WebServer /home/sonarqube/sonarqube-6.7.7/temp/sq-process3802828291335449308properties
2022.02.10 10:05:11 INFO  app[][o.s.a.SchedulerImpl] Process [web] is stopped

And the full log

Launching a JVM...
Wrapper (Version 3.2.3) http://wrapper.tanukisoftware.org
  Copyright 1999-2006 Tanuki Software, Inc.  All Rights Reserved.

2022.02.10 10:04:51 INFO  app[][o.s.a.AppFileSystem] Cleaning or creating temp directory /home/sonarqube/sonarqube-6.7.7/temp
2022.02.10 10:04:51 INFO  app[][o.s.a.es.EsSettings] Elasticsearch listening on /127.0.0.1:9001
2022.02.10 10:04:51 INFO  app[][o.s.a.p.ProcessLauncherImpl] Launch process[[key='es', ipcIndex=1, logFilenamePrefix=es]] from [/home/sonarqube/sonarqube-6.7.7/elasticsearch]: /home/sonarqube/sonarqube-6.7.7/elasticsearch/bin/elasticsearch -Epath.conf=/home/sonarqube/sonarqube-6.7.7/temp/conf/es
2022.02.10 10:04:51 INFO  app[][o.s.a.SchedulerImpl] Waiting for Elasticsearch to be up and running
2022.02.10 10:04:52 INFO  app[][o.e.p.PluginsService] no modules loaded
2022.02.10 10:04:52 INFO  app[][o.e.p.PluginsService] loaded plugin [org.elasticsearch.transport.Netty4Plugin]
2022.02.10 10:04:59 INFO  app[][o.s.a.SchedulerImpl] Process[es] is up
2022.02.10 10:04:59 INFO  app[][o.s.a.p.ProcessLauncherImpl] Launch process[[key='web', ipcIndex=2, logFilenamePrefix=web]] from [  ]: /usr/lib/jvm/java-1.8.0-openjdk-1.8.0.322.b06-2.el8_5.x86_64/jre/bin/java -Djava.awt.headless=true -Dfile.encoding=UTF-8 -Djava.io.tmpdir=/home/sonarqube/sonarqube-6.7.7/temp -Xmx512m -Xms128m -XX:+HeapDumpOnOutOfMemoryError -cp ./lib/common/*:./lib/server/*:/home/sonarqube/sonarqube-6.7.7/extensions/jdbc-driver/oracle/ojdbc7.jar org.sonar.server.app.WebServer /home/sonarqube/sonarqube-6.7.7/temp/sq-process3802828291335449308properties
2022.02.10 10:05:11 INFO  app[][o.s.a.SchedulerImpl] Process [web] is stopped
2022.02.10 10:05:11 INFO  app[][o.s.a.SchedulerImpl] Process [es] is stopped
2022.02.10 10:05:11 WARN  app[][o.s.a.p.AbstractProcessMonitor] Process exited with exit value [es]: 143
2022.02.10 10:05:11 INFO  app[][o.s.a.SchedulerImpl] SonarQube is stopped

Yes we are running this out of a home directory (because, because), but that shouldn’t be an issue. It was running for 5.6.7, so something in the web key launch process is hanging it up.

I’ve looked at other threads on here and yes, I have removed the /data/es5 file and I’ve cleared out my ES temp directory, but that didn’t have an effect. I am wondering if there is a different cache I might be missing from when I did the v5 LTS

I know you’ll all ask so here is also the es.log

2022.02.10 10:04:53 INFO  es[][o.e.n.Node] initializing ...
2022.02.10 10:04:53 INFO  es[][o.e.e.NodeEnvironment] using [1] data paths, mounts [[/home/sonarqube (/dev/mapper/dawg-lv_home_sonarqube)]], net usable_space [3.4gb], net total_space [4.9gb], spins? [no], types [xfs]
2022.02.10 10:04:53 INFO  es[][o.e.e.NodeEnvironment] heap size [494.9mb], compressed ordinary object pointers [true]
2022.02.10 10:04:53 INFO  es[][o.e.n.Node] node name [sonarqube], node ID [TgJYrlXDQEuiigPPr9yRMg]
2022.02.10 10:04:53 INFO  es[][o.e.n.Node] version[5.6.3], pid[1365679], build[1a2f265/2017-10-06T20:33:39.012Z], OS[Linux/4.18.0-348.el8.x86_64/amd64], JVM[Red Hat, Inc./OpenJDK 64-Bit Server VM/1.8.0_322/25.322-b06]
2022.02.10 10:04:53 INFO  es[][o.e.n.Node] JVM arguments [-XX:+UseConcMarkSweepGC, -XX:CMSInitiatingOccupancyFraction=75, -XX:+UseCMSInitiatingOccupancyOnly, -XX:+AlwaysPreTouch, -Xss1m, -Djava.awt.headless=true, -Dfile.encoding=UTF-8, -Djna.nosys=true, -Djdk.io.permissionsUseCanonicalPath=true, -Dio.netty.noUnsafe=true, -Dio.netty.noKeySetOptimization=true, -Dio.netty.recycler.maxCapacityPerThread=0, -Dlog4j.shutdownHookEnabled=false, -Dlog4j2.disable.jmx=true, -Dlog4j.skipJansi=true, -Xms512m, -Xmx512m, -XX:+HeapDumpOnOutOfMemoryError, -Des.path.home=/home/sonarqube/sonarqube-6.7.7/elasticsearch]
2022.02.10 10:04:53 INFO  es[][o.e.p.PluginsService] loaded module [aggs-matrix-stats]
2022.02.10 10:04:53 INFO  es[][o.e.p.PluginsService] loaded module [ingest-common]
2022.02.10 10:04:53 INFO  es[][o.e.p.PluginsService] loaded module [parent-join]
2022.02.10 10:04:53 INFO  es[][o.e.p.PluginsService] loaded module [percolator]
2022.02.10 10:04:53 INFO  es[][o.e.p.PluginsService] loaded module [reindex]
2022.02.10 10:04:53 INFO  es[][o.e.p.PluginsService] loaded module [transport-netty4]
2022.02.10 10:04:53 INFO  es[][o.e.p.PluginsService] no plugins loaded
2022.02.10 10:04:54 INFO  es[][o.e.d.DiscoveryModule] using discovery type [zen]
2022.02.10 10:04:55 INFO  es[][o.e.n.Node] initialized
2022.02.10 10:04:55 INFO  es[][o.e.n.Node] starting ...
2022.02.10 10:04:55 INFO  es[][o.e.t.TransportService] publish_address {127.0.0.1:9001}, bound_addresses {127.0.0.1:9001}
2022.02.10 10:04:58 INFO  es[][o.e.c.s.ClusterService] new_master {sonarqube}{TgJYrlXDQEuiigPPr9yRMg}{CCOC32G-S8CtUwiXf4kOVg}{127.0.0.1}{127.0.0.1:9001}{rack_id=sonarqube}, reason: zen-disco-elected-as-master ([0] nodes joined)
2022.02.10 10:04:58 INFO  es[][o.e.n.Node] started
2022.02.10 10:04:58 INFO  es[][o.e.g.GatewayService] recovered [8] indices into cluster_state
2022.02.10 10:04:59 INFO  es[][o.e.c.r.a.AllocationService] Cluster health status changed from [RED] to [GREEN] (reason: [shards started [[metadatas][0]] ...]).
2022.02.10 10:05:11 INFO  es[][o.e.n.Node] stopping ...
2022.02.10 10:05:11 INFO  es[][o.e.n.Node] stopped
2022.02.10 10:05:11 INFO  es[][o.e.n.Node] closing ...
2022.02.10 10:05:11 INFO  es[][o.e.n.Node] closed

Thanks for your help! I’m thinking it might be a database issue and we might just need to start with a fresh wipe, but figured I’d check here first before we do that.

ganncamp · February 11, 2022, 5:56pm

Hi,

Welcome to the community!

There’s one more log to look at. I’d say probably 95% of startup errors show up in web.log but since you’re not seeing anything there, I would also check ce.log. Compute Engine is the process I don’t see reflected in your sonar.log snippet so that’s the next place I’d look (especially since you’ve already looked at the other logs & they’re clean ).

HTH,
Ann

MTSteve · February 11, 2022, 8:53pm

Thanks, not seeing the ce.log in version 5.6.7, but I did look back at my logs from 5.6.7 and the LTS update might have corrupted the database. At this point we might just wipe the database and start over at 9.3…

ganncamp · February 14, 2022, 12:36pm

Hi,

Things have changed quite a bit since 5.6.7

I didn’t want to discourage you on your upgrade journey, but my first thought was that that probably would be easier.

Ann