Sonarqube 8.9.6 - project background task keeps failing

SonarQube
1

Version - 8.9.6 community edition
what are you trying to achieve - Project Backround task keeps failing
what have you tried so far to achieve this - Stop the services, deleting es7 folder sonar-home/data/es7 and re-index will kick-off after restarting the sonar services.

Error Details on one of the project and attached logs
logs.zip (361.0 KB)
sonarqube_web (5).zip (5.2 MB)

org.sonar.server.es.ElasticsearchException: Fail to execute es requestES refresh request on indices 'rules'
	at org.sonar.server.es.EsClient.execute(EsClient.java:313)
	at org.sonar.server.es.EsClient.refresh(EsClient.java:156)
	at org.sonar.server.es.BulkIndexer.stop(BulkIndexer.java:128)
	at org.sonar.server.rule.index.RuleIndexer.doIndexRules(RuleIndexer.java:150)
	at org.sonar.server.rule.index.RuleIndexer.index(RuleIndexer.java:123)
	at org.sonar.server.rule.index.RuleIndexer.postCommit(RuleIndexer.java:115)
	at org.sonar.server.rule.index.RuleIndexer.commitAndIndex(RuleIndexer.java:108)
	at org.sonar.ce.task.projectanalysis.issue.AdHocRuleCreator.persistAndIndex(AdHocRuleCreator.java:114)
	at org.sonar.ce.task.projectanalysis.issue.RuleRepositoryImpl.persistAndIndex(RuleRepositoryImpl.java:79)
	at org.sonar.ce.task.projectanalysis.issue.RuleRepositoryImpl.lambda$saveOrUpdateAddHocRules$0(RuleRepositoryImpl.java:75)
	at java.base/java.util.HashMap$Values.forEach(HashMap.java:977)
	at org.sonar.ce.task.projectanalysis.issue.RuleRepositoryImpl.saveOrUpdateAddHocRules(RuleRepositoryImpl.java:75)
	at org.sonar.ce.task.projectanalysis.step.PersistAdHocRulesStep.execute(PersistAdHocRulesStep.java:40)
	at org.sonar.ce.task.step.ComputationStepExecutor.executeStep(ComputationStepExecutor.java:81)
	at org.sonar.ce.task.step.ComputationStepExecutor.executeSteps(ComputationStepExecutor.java:72)
	at org.sonar.ce.task.step.ComputationStepExecutor.execute(ComputationStepExecutor.java:59)
	at org.sonar.ce.task.projectanalysis.taskprocessor.ReportTaskProcessor.process(ReportTaskProcessor.java:81)
	at org.sonar.ce.taskprocessor.CeWorkerImpl$ExecuteTask.executeTask(CeWorkerImpl.java:212)
	at org.sonar.ce.taskprocessor.CeWorkerImpl$ExecuteTask.run(CeWorkerImpl.java:194)
	at org.sonar.ce.taskprocessor.CeWorkerImpl.findAndProcessTask(CeWorkerImpl.java:160)
	at org.sonar.ce.taskprocessor.CeWorkerImpl$TrackRunningState.get(CeWorkerImpl.java:135)
	at org.sonar.ce.taskprocessor.CeWorkerImpl.call(CeWorkerImpl.java:87)
	at org.sonar.ce.taskprocessor.CeWorkerImpl.call(CeWorkerImpl.java:53)
	at com.google.common.util.concurrent.TrustedListenableFutureTask$TrustedFutureInterruptibleTask.runInterruptibly(TrustedListenableFutureTask.java:125)
	at com.google.common.util.concurrent.InterruptibleTask.run(InterruptibleTask.java:69)
	at com.google.common.util.concurrent.TrustedListenableFutureTask.run(TrustedListenableFutureTask.java:78)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: java.lang.RuntimeException: Request cannot be executed; I/O reactor status: STOPPED
	at org.elasticsearch.client.RestClient.extractAndWrapCause(RestClient.java:904)
	at org.elasticsearch.client.RestClient.performRequest(RestClient.java:288)
	at org.elasticsearch.client.RestClient.performRequest(RestClient.java:276)
	at org.elasticsearch.client.RestHighLevelClient.performClientRequest(RestHighLevelClient.java:2699)
	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.IndicesClient.refresh(IndicesClient.java:900)
	at org.sonar.server.es.EsClient.lambda$refresh$9(EsClient.java:156)
	at org.sonar.server.es.EsClient.execute(EsClient.java:311)
	... 31 more
Caused by: java.lang.IllegalStateException: Request cannot be executed; I/O reactor status: STOPPED
	at org.apache.http.util.Asserts.check(Asserts.java:46)
	at org.apache.http.impl.nio.client.CloseableHttpAsyncClientBase.ensureRunning(CloseableHttpAsyncClientBase.java:90)
	at org.apache.http.impl.nio.client.InternalHttpAsyncClient.execute(InternalHttpAsyncClient.java:123)
	at org.elasticsearch.client.RestClient.performRequest(RestClient.java:284)
	... 39 more
2

Hi,

Thanks for providing the logs in your OP!

It looks like they’re really big because you’ve turned them up to DEBUG level. They get really big really fast that way. And it’s really not needed in day-to-day operation. You should turn them back down to INFO as soon as practical.

Regarding your problem, your Background task log references an ES problem, so that’s the log I went to. 35k lines was a bit much to get through, so I just deleted all the DEBUG lines. That left me with a bunch of exceptions like this:

2022.07.08 12:14:21 WARN  es[][stderr] java.lang.reflect.InvocationTargetException
2022.07.08 12:14:21 WARN  es[][stderr] 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2022.07.08 12:14:21 WARN  es[][stderr] 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
2022.07.08 12:14:21 WARN  es[][stderr] 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2022.07.08 12:14:21 WARN  es[][stderr] 	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
2022.07.08 12:14:21 WARN  es[][stderr] 	at java.instrument/sun.instrument.InstrumentationImpl.loadClassAndStartAgent(InstrumentationImpl.java:513)
2022.07.08 12:14:21 WARN  es[][stderr] 	at java.instrument/sun.instrument.InstrumentationImpl.loadClassAndCallAgentmain(InstrumentationImpl.java:535)
2022.07.08 12:14:21 WARN  es[][stderr] Caused by: java.security.AccessControlException: access denied ("java.lang.RuntimePermission" "accessClassInPackage.jdk.internal.org.objectweb.asm")
2022.07.08 12:14:21 WARN  es[][stderr] 	at java.base/java.security.AccessControlContext.checkPermission(AccessControlContext.java:472)
2022.07.08 12:14:21 WARN  es[][stderr] 	at java.base/java.security.AccessController.checkPermission(AccessController.java:897)
2022.07.08 12:14:21 WARN  es[][stderr] 	at java.base/java.lang.SecurityManager.checkPermission(SecurityManager.java:322)
2022.07.08 12:14:21 WARN  es[][stderr] 	at java.base/java.lang.SecurityManager.checkPackageAccess(SecurityManager.java:1238)
2022.07.08 12:14:21 WARN  es[][stderr] 	at java.base/jdk.internal.loader.ClassLoaders$AppClassLoader.loadClass(ClassLoaders.java:174)
2022.07.08 12:14:21 WARN  es[][stderr] 	at java.base/java.lang.ClassLoader.loadClass(ClassLoader.java:522)
2022.07.08 12:14:21 WARN  es[][stderr] 	at Log4jHotPatch.asmVersion(Log4jHotPatch.java:71)
2022.07.08 12:14:21 WARN  es[][stderr] 	at Log4jHotPatch.agentmain(Log4jHotPatch.java:93)
2022.07.08 12:14:21 WARN  es[][stderr] 	... 6 more

The most interesting part of this for me is

Log4jHotPatch

It seems that you’ve hacked your instance out of concern about the Log4J problems reported in December. There was no need, and you should return to a canonical install immediately.

This thread offers more information:

 
HTH,
Ann

3

@ganncamp thanks for your reply and recommendation. Just want to confirm I need to update sonar.properties with the value sonar.search.javaAdditionalOpts=-Dlog4j2.formatMsgNoLookups=true right? can you please confirm?

4

Hi,

Did you check the post I referenced? All you need to do is install a current, canonical version.

 
Ann

5

@ganncamp, so upgrading SonarQube 8.9.9 LTS will resolve this issue. please confirm.

6

Confirm.

7

Thanks @ganncamp