SonarQube service getting stopped automatically after starting and running for approx 1-1.5 min

[arpit agarwal]

I have SonarQube 5.6.1 LTS version on my machine, but when I starts the service it automatically stops after a fixed duration.

Please find below the logs:

2017.11.22 09:24:43 INFO  app[o.s.a.AppFileSystem] Cleaning or creating temp directory C:\sonarqube-5.6.1\temp

SonarQube started.

2017.11.22 09:25:04 INFO  app[o.s.p.m.JavaProcessLauncher] Launch process[es]: C:\Program Files\Java\jre1.8.0_144\bin\java -Djava.awt.headless=true -Xmx1G -Xms256m -Xss256k -Djava.net.preferIPv4Stack=true -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:CMSInitiatingOccupancyFraction=75 -XX:+UseCMSInitiatingOccupancyOnly -XX:+HeapDumpOnOutOfMemoryError -Djava.io.tmpdir=C:\sonarqube-5.6.1\temp -javaagent:C:\Program Files\Java\jre1.8.0_144\lib\management-agent.jar -cp ./lib/common/*;./lib/search/* org.sonar.search.SearchServer C:\sonarqube-5.6.1\temp\sq-process3467430485471449665properties

2017.11.22 09:25:06 INFO   es[o.s.p.ProcessEntryPoint]  Starting es

2017.11.22 09:25:06 INFO   es[o.s.s.EsSettings]  Elasticsearch listening on 127.0.0.1:9001

2017.11.22 09:25:06 INFO   es[o.elasticsearch.node]  [sonar-1511339083605] version[1.7.5], pid[2664], build[00f95f4/2016-02-02T09:55:30Z]

2017.11.22 09:25:06 INFO   es[o.elasticsearch.node]  [sonar-1511339083605] initializing ...

2017.11.22 09:25:06 INFO   es[o.e.plugins]  [sonar-1511339083605] loaded [], sites []

2017.11.22 09:25:08 INFO   es[o.elasticsearch.env]  [sonar-1511339083605] using [1] data paths, mounts [[(C:)]], net usable_space [33.5gb], net total_space [129.6gb], types [NTFS]

2017.11.22 09:25:11 WARN   es[o.e.bootstrap]  JNA not found. native methods will be disabled.

2017.11.22 09:25:12 INFO   es[o.elasticsearch.node]  [sonar-1511339083605] initialized

2017.11.22 09:25:12 INFO   es[o.elasticsearch.node]  [sonar-1511339083605] starting ...

2017.11.22 09:25:13 INFO   es[o.e.transport]  [sonar-1511339083605] bound_address {inet[/127.0.0.1:9001]}, publish_address {inet[/127.0.0.1:9001]}

2017.11.22 09:25:13 INFO   es[o.e.discovery]  [sonar-1511339083605] sonarqube/15G4dzy-RW6D2wSL__KU-w

2017.11.22 09:25:16 INFO   es[o.e.cluster.service]  [sonar-1511339083605] new_master [sonar-1511339083605][15G4dzy-RW6D2wSL__KU-w][FRILM-EV-SONAR5][inet[/127.0.0.1:9001]]{rack_id=sonar-1511339083605}, reason: zen-disco-join (elected_as_master)

2017.11.22 09:25:16 INFO   es[o.elasticsearch.node]  [sonar-1511339083605] started

2017.11.22 09:25:16 INFO   es[o.e.gateway]  [sonar-1511339083605] recovered [6] indices into cluster_state

2017.11.22 09:25:48 INFO  app[o.s.p.m.Monitor] Process[es] is up

2017.11.22 09:25:48 INFO  app[o.s.p.m.JavaProcessLauncher] Launch process[web]: C:\Program Files\Java\jre1.8.0_144\bin\java -Djava.awt.headless=true -Dfile.encoding=UTF-8 -Djruby.management.enabled=false -Djruby.compile.invokedynamic=false -Xmx512m -Xms128m -XX:+HeapDumpOnOutOfMemoryError -Djava.net.preferIPv4Stack=true -Djava.io.tmpdir=C:\sonarqube-5.6.1\temp -javaagent:C:\Program Files\Java\jre1.8.0_144\lib\management-agent.jar -cp ./lib/common/*;./lib/server/*;C:\sonarqube-5.6.1\lib\jdbc\mysql\mysql-connector-java-5.1.35.jar org.sonar.server.app.WebServer C:\sonarqube-5.6.1\temp\sq-process7134497483271530702properties

2017.11.22 09:25:51 INFO  web[o.s.p.ProcessEntryPoint] Starting web

2017.11.22 09:25:52 INFO  web[o.s.s.a.TomcatContexts] Webapp directory: C:\sonarqube-5.6.1\web

2017.11.22 09:25:53 INFO  web[o.a.c.h.Http11NioProtocol] Initializing ProtocolHandler ["http-nio-0.0.0.0-9000"]

2017.11.22 09:25:53 INFO  web[o.a.t.u.n.NioSelectorPool] Using a shared selector for servlet write/read

2017.11.22 09:25:55 INFO  web[o.s.s.p.ServerImpl] SonarQube Server / 5.6.1 / 07c82b2477ac69126115671fe56d53c2ff47d5f5

2017.11.22 09:25:55 INFO  web[o.sonar.db.Database] Create JDBC data source for jdbc:mysql://localhost:3306/sonar?useUnicode=true&characterEncoding=utf8&rewriteBatchedStatements=true&useConfigs=maxPerformance

2017.11.22 09:25:57 ERROR web[o.a.c.c.C.[.[.[/]] Exception sending context initialized event to listener instance of class org.sonar.server.platform.PlatformServletContextListener

org.sonar.api.utils.MessageException: Database was upgraded to a more recent of SonarQube. Backup must probably be restored or db settings are incorrect.

2017.11.22 09:25:57 ERROR web[o.a.c.c.StandardContext] One or more listeners failed to start. Full details will be found in the appropriate container log file

2017.11.22 09:25:57 ERROR web[o.a.c.c.StandardContext] Context [] startup failed due to previous errors

2017.11.22 09:25:57 WARN  web[o.a.c.l.WebappClassLoaderBase] The web application [ROOT] appears to have started a thread named [Abandoned connection cleanup thread] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:

 java.lang.Object.wait(Native Method)

 java.lang.ref.ReferenceQueue.remove(Unknown Source)

 com.mysql.jdbc.AbandonedConnectionCleanupThread.run(AbandonedConnectionCleanupThread.java:43)

2017.11.22 09:25:57 WARN  web[o.a.c.l.WebappClassLoaderBase] The web application [ROOT] appears to have started a thread named [Timer-0] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:

 java.lang.Object.wait(Native Method)

 java.util.TimerThread.mainLoop(Unknown Source)

 java.util.TimerThread.run(Unknown Source)

2017.11.22 09:25:57 INFO  web[o.a.c.h.Http11NioProtocol] Starting ProtocolHandler ["http-nio-0.0.0.0-9000"]

2017.11.22 09:25:57 INFO  web[o.s.s.a.TomcatAccessLog] Web server is started

2017.11.22 09:25:57 INFO  web[o.s.s.a.EmbeddedTomcat] HTTP connector enabled on port 9000

2017.11.22 09:25:57 WARN  web[o.s.p.ProcessEntryPoint] Fail to start web

java.lang.IllegalStateException: Webapp did not start

at org.sonar.server.app.EmbeddedTomcat.isUp(EmbeddedTomcat.java:84) ~[sonar-server-5.6.1.jar:na]

at org.sonar.server.app.WebServer.isUp(WebServer.java:47) [sonar-server-5.6.1.jar:na]

at org.sonar.process.ProcessEntryPoint.launch(ProcessEntryPoint.java:105) ~[sonar-process-5.6.1.jar:na]

at org.sonar.server.app.WebServer.main(WebServer.java:68) [sonar-server-5.6.1.jar:na]

2017.11.22 09:25:57 INFO  web[o.a.c.h.Http11NioProtocol] Pausing ProtocolHandler ["http-nio-0.0.0.0-9000"]

2017.11.22 09:25:59 INFO  web[o.a.c.h.Http11NioProtocol] Stopping ProtocolHandler ["http-nio-0.0.0.0-9000"]

2017.11.22 09:25:59 INFO  web[o.a.c.h.Http11NioProtocol] Destroying ProtocolHandler ["http-nio-0.0.0.0-9000"]

2017.11.22 09:25:59 INFO  web[o.s.s.a.TomcatAccessLog] Web server is stopped

2017.11.22 09:25:59 INFO  app[o.s.p.m.Monitor] Process[es] is stopping

2017.11.22 09:26:00 INFO   es[o.s.p.StopWatcher]  Stopping process

2017.11.22 09:26:00 INFO   es[o.elasticsearch.node]  [sonar-1511339083605] stopping ...

2017.11.22 09:26:00 INFO   es[o.elasticsearch.node]  [sonar-1511339083605] stopped

2017.11.22 09:26:00 INFO   es[o.elasticsearch.node]  [sonar-1511339083605] closing ...

2017.11.22 09:26:00 INFO   es[o.elasticsearch.node]  [sonar-1511339083605] closed

2017.11.22 09:26:01 INFO  app[o.s.p.m.Monitor] Process[es] is stopped

<-- Wrapper Stopped

Can anyone please help me regarding the same ?

Thanks & Regards,

Arpit

[Scott B.]

Hi.

Please pay attention to your log:

2017.11.22 09:25:57 ERROR web[o.a.c.c.C.[.[.[/]] Exception sending context initialized event to listener instance of class org.sonar.server.platform.PlatformServletContextListener

org.sonar.api.utils.MessageException: Database was upgraded to a more recent of SonarQube. Backup must probably be restored or db settings are incorrect.

Are you sure that is not the case? Looks like you upgraded your db to a new version of SonarQube and now you're trying to start an older one.

[arpit agarwal]

Hi,

I have indeed updated SonarQube to LTS version 6.7 but the problem persists. Could you please help me with the same. Below are the updated logs: 

2017.11.22 12:11:58 INFO  app[][o.s.a.AppFileSystem] Cleaning or creating temp directory C:\sonarqube-6.7\temp

2017.11.22 12:11:59 INFO  app[][o.s.a.es.EsSettings] Elasticsearch listening on /127.0.0.1:9001

2017.11.22 12:11:59 INFO  app[][o.s.a.p.ProcessLauncherImpl] Launch process[[key='es', ipcIndex=1, logFilenamePrefix=es]] from [C:\sonarqube-6.7\elasticsearch]: C:\Program Files\Java\jre1.8.0_144\bin\java -XX:+UseConcMarkSweepGC -XX:CMSInitiatingOccupancyFraction=75 -XX:+UseCMSInitiatingOccupancyOnly -XX:+AlwaysPreTouch -server -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 -Delasticsearch -Des.path.home=C:\sonarqube-6.7\elasticsearch -cp lib/* org.elasticsearch.bootstrap.Elasticsearch -Epath.conf=C:\sonarqube-6.7\temp\conf\es

2017.11.22 12:11:59 INFO  app[][o.s.a.SchedulerImpl] Waiting for Elasticsearch to be up and running

2017.11.22 12:12:00 INFO  app[][o.e.p.PluginsService] no modules loaded

2017.11.22 12:12:00 INFO  app[][o.e.p.PluginsService] loaded plugin [org.elasticsearch.transport.Netty4Plugin]

Waiting to start...

SonarQube started.

2017.11.22 12:12:22 INFO  app[][o.s.a.SchedulerImpl] Process[es] is up

2017.11.22 12:12:22 INFO  app[][o.s.a.p.ProcessLauncherImpl] Launch process[[key='web', ipcIndex=2, logFilenamePrefix=web]] from [C:\sonarqube-6.7]: C:\Program Files\Java\jre1.8.0_144\bin\java -Djava.awt.headless=true -Dfile.encoding=UTF-8 -Djava.io.tmpdir=C:\sonarqube-6.7\temp -Xmx512m -Xms128m -XX:+HeapDumpOnOutOfMemoryError -cp ./lib/common/*;./lib/server/*;C:\sonarqube-6.7\lib\jdbc\mysql\mysql-connector-java-5.1.42.jar org.sonar.server.app.WebServer C:\sonarqube-6.7\temp\sq-process3504435886428385398properties

2017.11.22 12:13:03 INFO  app[][o.s.a.SchedulerImpl] Process[web] is up

2017.11.22 12:13:03 INFO  app[][o.s.a.p.ProcessLauncherImpl] Launch process[[key='ce', ipcIndex=3, logFilenamePrefix=ce]] from [C:\sonarqube-6.7]: C:\Program Files\Java\jre1.8.0_144\bin\java -Djava.awt.headless=true -Dfile.encoding=UTF-8 -Djava.io.tmpdir=C:\sonarqube-6.7\temp -Xmx2048m -Xms128m -XX:+HeapDumpOnOutOfMemoryError -cp ./lib/common/*;./lib/server/*;./lib/ce/*;C:\sonarqube-6.7\lib\jdbc\mysql\mysql-connector-java-5.1.42.jar org.sonar.ce.app.CeServer C:\sonarqube-6.7\temp\sq-process5598174220570001692properties

2017.11.22 12:13:36 INFO  app[][o.s.a.SchedulerImpl] Process [ce] is stopped

2017.11.22 12:13:59 INFO  app[][o.s.a.SchedulerImpl] Process [web] is stopped

2017.11.22 12:13:59 INFO  app[][o.s.a.SchedulerImpl] Process [es] is stopped

2017.11.22 12:13:59 INFO  app[][o.s.a.SchedulerImpl] SonarQube is stopped

<-- Wrapper Stopped

Thanks & Regards,

Arpit

[Colin Mueller]

On 6.7 you're going to have multiple logs: web.log, sonar.log, es.log, ce.log

Check out the others to see if the issue gets described in more detail.