SonarQube Analysis takes some times too long

Ismail_khamsi · December 2, 2020, 10:35am

Hi,
I have a problem with SonarQube Analysis which sometimes takes too long.
Developer edition V8.5.1.38104
DB:PostgreSQL
DB and server install in the same machine (in the SSD hard drive)

what are the possible causes that PR/MR analysis can sometimes go in 5s and sometimes to 40min?

Thank you for your help

pierreguillot · December 2, 2020, 3:29pm

Hi, there is a purge mechanism that clean up “old” data. It’s run at the end of each analysis. Criteria for rows to purge are timestamp-based. So at some point, there is nothing to purge, and one day later you could have 300 PR & branches eligible for the purge mechanism, which takes time.

You can enable purge profiling to confirm or deny this hypothesis, and maybe help narrow down the issue. Add the sonar.showProfiling=true property to your sonar.properties & restart SonarQube. Next time a purge happen, you should see logs like this in ce.log:

 2020.07.31 12:41:07 INFO ce[AXOkdgQP4WBcbHHv1D0Z][o.s.c.t.p.p.ProjectCleaner] 
 2020.07.31 12:41:07 INFO ce[AXOkdgQP4WBcbHHv1D0Z][o.s.c.t.p.p.ProjectCleaner] -------- Profiling for purge: 81ms --------
 2020.07.31 12:41:07 INFO ce[AXOkdgQP4WBcbHHv1D0Z][o.s.c.t.p.p.ProjectCleaner] 
 2020.07.31 12:41:07 INFO ce[AXOkdgQP4WBcbHHv1D0Z][o.s.c.t.p.p.ProjectCleaner] o deleteCeActivityBefore (ce_task_input): 9ms (11%)
 2020.07.31 12:41:07 INFO ce[AXOkdgQP4WBcbHHv1D0Z][o.s.c.t.p.p.ProjectCleaner] o deleteCeActivityBefore (ce_scanner_context): 8ms (9%)
 2020.07.31 12:41:07 INFO ce[AXOkdgQP4WBcbHHv1D0Z][o.s.c.t.p.p.ProjectCleaner] o deleteCeActivityBefore (ce_task_message): 8ms (9%)
 2020.07.31 12:41:07 INFO ce[AXOkdgQP4WBcbHHv1D0Z][o.s.c.t.p.p.ProjectCleaner] o deleteCeActivityBefore (ce_task_characteristics): 8ms (9%)
 2020.07.31 12:41:07 INFO ce[AXOkdgQP4WBcbHHv1D0Z][o.s.c.t.p.p.ProjectCleaner] o deleteCeActivityBefore (ce_activity): 8ms (9%)
 2020.07.31 12:41:07 INFO ce[AXOkdgQP4WBcbHHv1D0Z][o.s.c.t.p.p.ProjectCleaner] o updatePurgeStatusToOne (snapshots): 3ms (3%)
 2020.07.31 12:41:07 INFO ce[AXOkdgQP4WBcbHHv1D0Z][o.s.c.t.p.p.ProjectCleaner] o deleteAnalysisDuplications (duplications_index): 1ms (1%)
 2020.07.31 12:41:07 INFO ce[AXOkdgQP4WBcbHHv1D0Z][o.s.c.t.p.p.ProjectCleaner] o purgeDisabledComponents (file_sources): 1ms (1%)
 2020.07.31 12:41:07 INFO ce[AXOkdgQP4WBcbHHv1D0Z][o.s.c.t.p.p.ProjectCleaner] o purgeDisabledComponents (unresolved_issues): 1ms (1%)
 2020.07.31 12:41:07 INFO ce[AXOkdgQP4WBcbHHv1D0Z][o.s.c.t.p.p.ProjectCleaner] 
 2020.07.31 12:41:07 INFO ce[AXOkdgQP4WBcbHHv1D0Z][o.s.c.t.p.p.ProjectCleaner] -------- End of profiling for purge --------
 2020.07.31 12:41:07 INFO ce[AXOkdgQP4WBcbHHv1D0Z][o.s.c.t.p.p.ProjectCleaner]

Ismail_khamsi · December 2, 2020, 4:20pm

Thank you for your response. I checked ce.log and found that, we spend a long time in PULL request decoration after “failed to connect to git”.

    2020.12.02 **16:09:44** INFO  ce[AXYkAHvnxZlDCZFSp480][c.s.C.D.D.I] GitLab's project ID from the scanner ('27') is overridden by the settings ('27')
2020.12.02 **16:47:19** ERROR ce[AXYkAHvnxZlDCZFSp480][c.s.C.D.D.B] An exception was thrown during Merge Request decoration : Failed to connect to git.xx.com/xx.xx.xx.xx:xx
2020.12.02 16:47:19 ERROR ce[AXYkAHvnxZlDCZFSp480][o.s.c.t.p.a.p.PostProjectAnalysisTasksExecutor] Execution of task class com.sonarsource.C.D.c failed
java.lang.IllegalStateException: Failed to connect to git.xx.com/xx.xx.xx.xx:xx
	at com.sonarsource.C.D.D.G.A(Unknown Source)
	at com.sonarsource.C.D.D.B.A(Unknown Source)
	at com.sonarsource.C.D.c.A(Unknown Source)
	at java.base/java.util.Optional.ifPresent(Optional.java:183)
	at com.sonarsource.C.D.c.B(Unknown Source)
	at com.sonarsource.C.D.c.A(Unknown Source)
	at org.sonar.ce.async.SynchronousAsyncExecution.addToQueue(SynchronousAsyncExecution.java:27)
	at com.sonarsource.C.D.c.A(Unknown Source)
	at java.base/java.util.Optional.ifPresent(Optional.java:183)
	at com.sonarsource.C.D.c.finished(Unknown Source)
	at org.sonar.ce.task.projectanalysis.api.posttask.PostProjectAnalysisTasksExecutor.executeTask(PostProjectAnalysisTasksExecutor.java:118)
	at org.sonar.ce.task.projectanalysis.api.posttask.PostProjectAnalysisTasksExecutor.finished(PostProjectAnalysisTasksExecutor.java:109)
	at org.sonar.ce.task.step.ComputationStepExecutor.executeListener(ComputationStepExecutor.java:91)
	at org.sonar.ce.task.step.ComputationStepExecutor.execute(ComputationStepExecutor.java:63)
	at org.sonar.ce.task.projectanalysis.taskprocessor.ReportTaskProcessor.process(ReportTaskProcessor.java:81)
	at org.sonar.ce.taskprocessor.CeWorkerImpl$ExecuteTask.executeTask(CeWorkerImpl.java:235)
	at org.sonar.ce.taskprocessor.CeWorkerImpl$ExecuteTask.run(CeWorkerImpl.java:217)
	at org.sonar.ce.taskprocessor.CeWorkerImpl.findAndProcessTask(CeWorkerImpl.java:162)
	at org.sonar.ce.taskprocessor.CeWorkerImpl$TrackRunningState.get(CeWorkerImpl.java:137)
	at org.sonar.ce.taskprocessor.CeWorkerImpl.call(CeWorkerImpl.java:89)
	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:834)
Caused by: java.net.ConnectException: Failed to connect to git.xx.com/xx.xx.xx.xx:xx
	at okhttp3.internal.connection.RealConnection.connectSocket(RealConnection.java:265)
	at okhttp3.internal.connection.RealConnection.connect(RealConnection.java:183)
	at okhttp3.internal.connection.ExchangeFinder.findConnection(ExchangeFinder.java:224)
	at okhttp3.internal.connection.ExchangeFinder.findHealthyConnection(ExchangeFinder.java:108)
	at okhttp3.internal.connection.ExchangeFinder.find(ExchangeFinder.java:88)
	at okhttp3.internal.connection.Transmitter.newExchange(Transmitter.java:169)
	at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.java:41)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:142)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:117)
	at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.java:94)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:142)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:117)
	at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.java:93)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:142)
	at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.java:88)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:142)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:117)
	at okhttp3.RealCall.getResponseWithInterceptorChain(RealCall.java:229)
	at okhttp3.RealCall.execute(RealCall.java:81)
	... 30 common frames omitted
Caused by: java.net.ConnectException: Connection timed out: connect
	at java.base/java.net.PlainSocketImpl.waitForConnect(Native Method)
	at java.base/java.net.PlainSocketImpl.socketConnect(PlainSocketImpl.java:107)
	at java.base/java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:399)
	at java.base/java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:242)
	at java.base/java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:224)
	at java.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:403)
	at java.base/java.net.Socket.connect(Socket.java:608)
	at okhttp3.internal.platform.Platform.connectSocket(Platform.java:130)
	at okhttp3.internal.connection.RealConnection.connectSocket(RealConnection.java:263)
	... 48 common frames omitted
2020.12.02 16:47:19 INFO  ce[AXYkAHvnxZlDCZFSp480][o.s.c.t.p.a.p.PostProjectAnalysisTasksExecutor] Pull Request decoration | status=FAILED | time=**2255501ms**

pierreguillot · December 2, 2020, 4:45pm

Thanks for the report. Are you using gitlab.com, or on-premise? In both case, you have a connectivity issue. It can be related to proxy, SSL configuration, DNS caching, etc.

Ismail_khamsi · December 3, 2020, 1:47pm

Thank you for your answer. I think the problem is similar to https://jira.sonarsource.com/browse/SONAR-13290
it’s not a connection problem because the MR decoration succeed if I start MR with code when we have 0 modification with master.
I’ll give you an answer after I’m testing your fix proposal at the link above

Ismail_khamsi · December 3, 2020, 2:53pm

the fix propose fix de bug. don’t forget to launch “gitlab-ctl reconfigures” to apply the changes made on gitlab.rb

pierreguillot · December 3, 2020, 3:29pm

Thanks a lot for sharing this us with. To be honest, I still fail to reproduce this issue locally on my gitlab on-prem instance. So we have no real solution right now to propose.

Do you think you could give me access (privately), to a dummy project on your GitLab instance, to allow me to debug this weird behaviour?

Ismail_khamsi · December 3, 2020, 3:52pm

I had the bug you reported in https://jira.sonarsource.com/browse/SONAR-13290
so by adding "nginx[‘custom_gitlab_server_config’] = “large_client_header_buffers 4 32k;\nhttp2_max_field_size 32k;\nhttp2_max_header_size 64k;\n” to gitlab.rb(https://ssl.microsofttranslator.com/bv.aspx?ref=TVert&from=&to=en&a=gitlab.rb) the sonar server no longer crashes on the MR decoration.

pierreguillot · December 4, 2020, 3:29pm

Hi, this issue has been fixed in SonarQube 8.6 that should be released next week. The nginx configuration workaround won’t be needed anymore

Chris · December 11, 2020, 9:00am

Hi,

SonarQube 8.6 is now available!
Thanks all for your help.

system · December 18, 2020, 9:00am

This topic was automatically closed 7 days after the last reply. New replies are no longer allowed.