Background Task Stuck on PR decoration with Gitlab

versions used

  • SonarQube: 8.1.0.31237
  • SonarScanner: 3.2.0.1227
  • Gitlab: 12.4.1

error observed

On certain projects in Gitlab the background task hangs for an extremely long time, e.g. tasks taking 2+ hours rather than < 5 seconds. The analysis runs successfully the time is taken trying to decorate the PR in Gitlab.

This so far only seems to happen on projects in sub-folders but is intermittent on those projects.

potential workaround

  • restart the server manually when this occurs
2020.03.06 10:43:51 ERROR ce[AXCvVjv3DSb6dQz2369M][o.s.c.t.p.a.p.PostProjectAnalysisTasksExecutor] Execution of task class com.sonarsource.C.D.a failed
java.lang.IllegalStateException: Couldn't kickstart handshaking
	at com.sonarsource.C.D.D.E.A(Unknown Source)
	at com.sonarsource.C.D.D.A.A(Unknown Source)
	at com.sonarsource.C.D.a.A(Unknown Source)
	at java.base/java.util.Optional.ifPresent(Optional.java:183)
	at com.sonarsource.C.D.a.B(Unknown Source)
	at com.sonarsource.C.D.a.A(Unknown Source)
	at org.sonar.ce.async.SynchronousAsyncExecution.addToQueue(SynchronousAsyncExecution.java:27)
	at com.sonarsource.C.D.a.A(Unknown Source)
	at java.base/java.util.Optional.ifPresent(Optional.java:183)
	at com.sonarsource.C.D.a.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:209)
	at org.sonar.ce.taskprocessor.CeWorkerImpl$ExecuteTask.run(CeWorkerImpl.java:191)
	at org.sonar.ce.taskprocessor.CeWorkerImpl.findAndProcessTask(CeWorkerImpl.java:158)
	at org.sonar.ce.taskprocessor.CeWorkerImpl$TrackRunningState.get(CeWorkerImpl.java:133)
	at org.sonar.ce.taskprocessor.CeWorkerImpl.call(CeWorkerImpl.java:85)
	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: javax.net.ssl.SSLException: Couldn't kickstart handshaking
	at java.base/sun.security.ssl.Alert.createSSLException(Alert.java:127)
	at java.base/sun.security.ssl.TransportContext.fatal(TransportContext.java:321)
	at java.base/sun.security.ssl.TransportContext.fatal(TransportContext.java:264)
	at java.base/sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:405)
	at okhttp3.internal.connection.RealConnection.connectTls(RealConnection.java:336)
	at okhttp3.internal.connection.RealConnection.establishProtocol(RealConnection.java:300)
	at okhttp3.internal.connection.RealConnection.connect(RealConnection.java:185)
	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:221)
	at okhttp3.RealCall.execute(RealCall.java:81)
	... 30 common frames omitted
	Suppressed: java.net.SocketException: Cannot send after socket shutdown: socket write error
		at java.base/java.net.SocketOutputStream.socketWrite0(Native Method)
		at java.base/java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:110)
		at java.base/java.net.SocketOutputStream.write(SocketOutputStream.java:150)
		at java.base/sun.security.ssl.SSLSocketOutputRecord.encodeAlert(SSLSocketOutputRecord.java:81)
		at java.base/sun.security.ssl.TransportContext.fatal(TransportContext.java:352)
		... 52 common frames omitted
Caused by: java.net.SocketException: Cannot send after socket shutdown: socket write error
	at java.base/java.net.SocketOutputStream.socketWrite0(Native Method)
	at java.base/java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:110)
	at java.base/java.net.SocketOutputStream.write(SocketOutputStream.java:150)
	at java.base/sun.security.ssl.SSLSocketOutputRecord.flush(SSLSocketOutputRecord.java:251)
	at java.base/sun.security.ssl.HandshakeOutStream.flush(HandshakeOutStream.java:89)
	at java.base/sun.security.ssl.ClientHello$ClientHelloKickstartProducer.produce(ClientHello.java:656)
	at java.base/sun.security.ssl.SSLHandshake.kickstart(SSLHandshake.java:515)
	at java.base/sun.security.ssl.ClientHandshakeContext.kickstart(ClientHandshakeContext.java:107)
	at java.base/sun.security.ssl.TransportContext.kickstart(TransportContext.java:228)
	at java.base/sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:395)
	... 50 common frames omitted
2020.03.06 10:43:51 INFO  ce[AXCvVjv3DSb6dQz2369M][o.s.c.t.p.a.p.PostProjectAnalysisTasksExecutor] Pull Request decoration | status=FAILED | time=1800222ms ```

Welcome to the community! Please upgrade to 8.2, as we resolved some issue with GitLab MR decoration.

Hi,

We have similar issue with GitLab pull request decoration step is stuck.

In our case the background job is stuck in “in-progress” state indefinitely. One job was stuck over 20h (Job stats: May 6, 2020 | 3:17:42 PM | 3:17:43 PM | 11:26:57 AM | 20h 9min) until we resterted the SonarQube service. Only way to get rid of the stuck job is to restart SonarQube server. Currently this is stopping our CI flow - we get stuck jobs 2-5 times per day.

Versions used
SonarQube Developer Edition 8.3.0.34182
GitLab 12.9.3-ee
SonarScanner for MSBuild 4.9

Error observed
GitLab Merge Request (pull request) analyze is submited to SonarQube server via SonarScanner for MSBuild 4.9. SonarQube starts to process the analyze results. Background job that processes the results stays in “In Progress” state indefinitely. It does not finish. All additionally added background processes will stay in Pending state.

Workaround
Restart SonarQube service from command line. You cannot restart service from the UI because then it will wait until the In Progress job is finished, which is never.

Details

SonarQube CE log:
2020.05.12 14:41:26 INFO ce[o.s.c.t.CeWorkerImpl] Execute task | project=xxx | type=REPORT | pullRequest=9092 | id=AXIIiNI1i1YWpSkRV34T | submitter=xxx
2020.05.12 14:41:27 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Extract report | status=SUCCESS | time=659ms
2020.05.12 14:41:27 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Persist scanner context | status=SUCCESS | time=10ms
2020.05.12 14:41:27 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Propagate analysis warnings from scanner report | status=SUCCESS | time=3ms
2020.05.12 14:41:27 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Execute DB migrations for current project | status=SUCCESS | time=1ms
2020.05.12 14:41:27 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Generate analysis UUID | status=SUCCESS | time=0ms
2020.05.12 14:41:27 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Load analysis metadata | status=SUCCESS | time=6ms
2020.05.12 14:41:27 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Initialize | status=SUCCESS | time=5ms
2020.05.12 14:41:27 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Verify billing | status=SUCCESS | time=0ms
2020.05.12 14:41:27 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Build tree of components | components=59 | status=SUCCESS | time=238ms
2020.05.12 14:41:27 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Validate project | status=SUCCESS | time=3ms
2020.05.12 14:41:27 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Load quality profiles | status=SUCCESS | time=198ms
2020.05.12 14:41:27 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Load Quality gate | status=SUCCESS | time=3ms
2020.05.12 14:41:27 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Load new code period | status=SUCCESS | time=0ms
2020.05.12 14:41:27 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Detect file moves | status=SUCCESS | time=0ms
2020.05.12 14:41:27 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Load duplications | duplications=560 | status=SUCCESS | time=137ms
2020.05.12 14:41:27 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Compute cross project duplications | status=SUCCESS | time=0ms
2020.05.12 14:41:27 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Compute size measures | status=SUCCESS | time=2ms
2020.05.12 14:41:27 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Compute new coverage | status=SUCCESS | time=5ms
2020.05.12 14:41:28 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Compute coverage measures | status=SUCCESS | time=393ms
2020.05.12 14:41:28 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Compute comment measures | status=SUCCESS | time=0ms
2020.05.12 14:41:28 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Copy custom measures | status=SUCCESS | time=2ms
2020.05.12 14:41:28 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Compute duplication measures | status=SUCCESS | time=13ms
2020.05.12 14:41:28 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Compute size measures on new code | status=SUCCESS | time=0ms
2020.05.12 14:41:28 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Compute language distribution | status=SUCCESS | time=0ms
2020.05.12 14:41:28 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Compute test measures | status=SUCCESS | time=0ms
2020.05.12 14:41:28 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Compute complexity measures | status=SUCCESS | time=0ms
2020.05.12 14:41:28 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Load measure computers | status=SUCCESS | time=1ms
2020.05.12 14:41:28 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Compute Quality Profile status | status=SUCCESS | time=3ms
2020.05.12 14:41:28 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Execute component visitors | status=SUCCESS | time=309ms
2020.05.12 14:41:28 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Checks executed after computation of measures | status=SUCCESS | time=4ms
2020.05.12 14:41:28 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Compute Quality Gate measures | status=SUCCESS | time=2ms
2020.05.12 14:41:28 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Compute Quality profile measures | status=SUCCESS | time=0ms
2020.05.12 14:41:28 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Generate Quality profile events | status=SUCCESS | time=1ms
2020.05.12 14:41:28 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Generate Quality gate events | status=SUCCESS | time=0ms
2020.05.12 14:41:28 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Persist components | status=SUCCESS | time=60ms
2020.05.12 14:41:28 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Persist analysis | status=SUCCESS | time=2ms
2020.05.12 14:41:28 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Persist analysis properties | status=SUCCESS | time=3ms
2020.05.12 14:41:28 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Persist measures | inserts=59 | status=SUCCESS | time=8ms
2020.05.12 14:41:29 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Persist live measures | insertsOrUpdates=2915 | status=SUCCESS | time=458ms
2020.05.12 14:41:29 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Persist duplication data | insertsOrUpdates=0 | status=SUCCESS | time=2ms
2020.05.12 14:41:29 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Persist new ad hoc Rules | status=SUCCESS | time=42ms
2020.05.12 14:41:29 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Persist issues | cacheSize=8 KB | inserts=14 | updates=0 | merged=0 | status=SUCCESS | time=32ms
2020.05.12 14:41:29 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Persist project links | status=SUCCESS | time=0ms
2020.05.12 14:41:29 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Persist events | status=SUCCESS | time=5ms
2020.05.12 14:41:29 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Persist sources | status=SUCCESS | time=147ms
2020.05.12 14:41:29 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Persist cross project duplications | status=SUCCESS | time=0ms
2020.05.12 14:41:29 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Enable analysis | status=SUCCESS | time=5ms
2020.05.12 14:41:29 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Update last usage date of quality profiles | status=SUCCESS | time=7ms
2020.05.12 14:41:29 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Purge db | status=SUCCESS | time=44ms
2020.05.12 14:41:29 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Index analysis | status=SUCCESS | time=41ms
2020.05.12 14:41:29 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Send issue notifications | status=SUCCESS | time=0ms
2020.05.12 14:41:29 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Publish task results | status=SUCCESS | time=0ms
2020.05.12 14:41:29 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.s.ComputationStepExecutor] Trigger refresh of Portfolios and Applications | status=SUCCESS | time=0ms
2020.05.12 14:41:29 INFO ce[AXIIiNI1i1YWpSkRV34T][o.s.c.t.p.a.p.PostProjectAnalysisTasksExecutor] Webhooks | globalWebhooks=0 | projectWebhooks=0 | status=SUCCESS | time=3ms

Welcome to the community forum. Can you please try the workaround described in this ticket and tell us if it fix the issue?

1 Like

Thank you for referring to the workaround.

Indeed, we are using Nginx reverse proxy, so this could apply to our case. I will contact our ops and try out the workaround, and after that let you know it fixed the issue.

Hi!

We made the changes to the GitLab config yesterday and have now ran the SonarQube without problems for about a day. In that time SQ has analyzed all kinds of pull requests and branches without hiccups. Seems that the workaround fixed the issue.

Thank you very much for fast response and pointing us to the workaround! This gave us confidence to continue using the SonarQube server.

2 Likes