SonarQube Tasks for Azure DevOps getting Stuck until Canceled

Our team recently ran into issues with the SonarQube tasks built in to Azure DevOps.

  • SonarQube Version: Enterprise Edition, 8.9.7.52159
  • AZDO SonarQube Tasks
    • Prepare Analysis Configuration: 5.4.0
    • Run Code Analysis: 5.4.0
    • Publish Quality Gate Result: 5.0.1

Issue
Between 15-25% of our gated and CI builds were failing due to timeouts of the SonarQube tasks. The tasks would get “stuck” when trying to connect to the SonarQube server. Any task that did get stuck would stay stuck until either manually canceled or canceled by the AZDO build (default: 60 minutes).

Requeuing builds worked, but sometimes it would take a few times before it went through successfully.

This caused slowdown for our development teams. 1) It reduced the throughput of the AZDO agents in our agent pool. 2) It caused jobs to have to be added back to the pool queue to be retried. 3) There was a lot of manual effort to keep requeuing these items. 4) Developers had to wait a long time for feedback.

Ultimately, the root cause was network related. It is over my head, but it had something to do with the way our on on-prem network (where the our build servers reside) was communicating with our public cloud (where we’re hosting our SonarQube server). This has been resolved and we are not seeing the issue anymore.

Bug
Even though the root cause was with our network, we would still like to see some more resiliency in the AZDO SonarQube tasks. These tasks should be able to handle network failures and not get stuck (do not trust the TCP “ESTABLISHED” state). Even better, these tasks should be able to retry on their own a few times so that we do not have to retry the entire build.

Request:

  • SonarQube tasks for Azure DevOps do not get into a stuck state.
  • SonarQube tasks for AZDO apply some sort of retry to reduce need for manually requeuing builds.

Timeout Logs

Prepare Analysis Configuration

  • Normal completion time: 1-4 seconds
  • AZDO timeout for task: 1 minute (to prevent agent from being consumed for 60 minutes)
  • Gets stuck when attempting to get SonarQube version from server
...
2022-04-28T17:36:06.5207283Z 13:36:06.518  Updating build integration targets...
2022-04-28T17:36:06.5260955Z 13:36:06.518  The file SonarQube.Integration.ImportBefore.targets is up to date at C:\Windows\ServiceProfiles\NetworkService\AppData\Local\Microsoft\MSBuild\4.0\Microsoft.Common.targets\ImportBefore
2022-04-28T17:36:06.5264161Z 13:36:06.518  The file SonarQube.Integration.ImportBefore.targets is up to date at C:\Windows\ServiceProfiles\NetworkService\AppData\Local\Microsoft\MSBuild\10.0\Microsoft.Common.targets\ImportBefore
2022-04-28T17:36:06.5267220Z 13:36:06.518  The file SonarQube.Integration.ImportBefore.targets is up to date at C:\Windows\ServiceProfiles\NetworkService\AppData\Local\Microsoft\MSBuild\11.0\Microsoft.Common.targets\ImportBefore
2022-04-28T17:36:06.5270264Z 13:36:06.518  The file SonarQube.Integration.ImportBefore.targets is up to date at C:\Windows\ServiceProfiles\NetworkService\AppData\Local\Microsoft\MSBuild\12.0\Microsoft.Common.targets\ImportBefore
2022-04-28T17:36:06.5273288Z 13:36:06.518  The file SonarQube.Integration.ImportBefore.targets is up to date at C:\Windows\ServiceProfiles\NetworkService\AppData\Local\Microsoft\MSBuild\14.0\Microsoft.Common.targets\ImportBefore
2022-04-28T17:36:06.5276402Z 13:36:06.518  The file SonarQube.Integration.ImportBefore.targets is up to date at C:\Windows\ServiceProfiles\NetworkService\AppData\Local\Microsoft\MSBuild\15.0\Microsoft.Common.targets\ImportBefore
2022-04-28T17:36:06.5279426Z 13:36:06.518  The file SonarQube.Integration.ImportBefore.targets is up to date at C:\Windows\ServiceProfiles\NetworkService\AppData\Local\Microsoft\MSBuild\Current\Microsoft.Common.targets\ImportBefore
2022-04-28T17:36:06.5312350Z 13:36:06.518  Installed SonarQube.Integration.targets to C:\vsts\agent1\_work\1335\.sonarqube\bin\targets
2022-04-28T17:36:06.5325124Z 13:36:06.518  Creating config and output folders...
2022-04-28T17:36:06.5338854Z 13:36:06.518  Creating directory: C:\vsts\agent1\_work\1335\.sonarqube\conf
2022-04-28T17:36:06.5344906Z 13:36:06.533  Creating directory: C:\vsts\agent1\_work\1335\.sonarqube\out
2022-04-28T17:36:06.5649515Z 13:36:06.549  Downloading from https://<my-sonarqube-server.url>/api/server/version...
2022-04-28T17:37:04.8343764Z ##[error]The task has timed out.
2022-04-28T17:37:04.8356906Z ##[section]Finishing: SQ Prepare .NET Analysis Configuration

Run Code Analysis

  • Normal completion time: based on project size (20 seconds to 20 minutes)
  • Do not have an example of Analysis with diagnostics on. This was manually canceled.
...
2022-04-27T18:42:33.0561186Z INFO: Java 11.0.10 Oracle Corporation (64-bit)
2022-04-27T18:42:33.0561696Z INFO: Windows Server 2016 10.0 amd64
2022-04-27T18:42:33.3987823Z INFO: User cache: C:\Windows\ServiceProfiles\NetworkService\.sonar\cache
2022-04-27T18:47:09.8733280Z ##[error]The operation was canceled.
2022-04-27T18:47:09.8746532Z ##[section]Finishing: SQ Run .NET Code Analysis

Publish Quality Gate Result

  • Normal completion time: 3-80 seconds
  • AZDO timeout for task: 6 minutes (to prevent agent from being consumed for 60 minutes)
  • Gets stuck when attempting to call a SonarQube server api.
...
2022-04-28T17:38:57.1969562Z ##[debug]Agent.ProxyUrl=undefined
2022-04-28T17:38:57.1970430Z ##[debug]Agent.CAInfo=undefined
2022-04-28T17:38:57.1971216Z ##[debug]Agent.ClientCert=undefined
2022-04-28T17:38:57.1976138Z ##[debug]Agent.SkipCertValidation=undefined
2022-04-28T17:38:57.8101054Z ##[debug]SONARQUBE_SCANNER_PARAMS={"<redacted params>"}
2022-04-28T17:38:57.8114318Z ##[debug]SONARQUBE_ENDPOINT=***
2022-04-28T17:38:57.8116679Z ##[debug][SQ] API GET: '/api/metrics/search' with query "{"f":"name","ps":500}"
2022-04-28T17:44:56.8107255Z ##[error]The task has timed out.
2022-04-28T17:44:56.8118802Z ##[section]Finishing: SQ Publish .NET Quality Gate Result

Connectivity Failure Logs
These are logs from tasks which ran but failed due to connectivity failures. Not ideal, but we would still rather fail fast than get indefinitely stuck. We feel that some of these areas would benefit from built in retry logic.

Analysis: “Can not be reached”

...
2022-04-28T17:40:45.4867917Z 13:40:45.483 DEBUG: Create: C:\Windows\ServiceProfiles\NetworkService\.sonar\cache\_tmp
2022-04-28T17:40:45.4899332Z 13:40:45.483 DEBUG: Extract sonar-scanner-api-batch in temp...
2022-04-28T17:40:45.4956918Z 13:40:45.483 DEBUG: Get bootstrap index...
2022-04-28T17:40:45.4957533Z 13:40:45.483 DEBUG: Download: https://<my-sonarqube-server.url>/batch/index
2022-04-28T17:45:45.6342550Z 13:45:45.629 INFO: ------------------------------------------------------------------------
2022-04-28T17:45:45.6343655Z 13:45:45.629 INFO: EXECUTION FAILURE
2022-04-28T17:45:45.6344098Z 13:45:45.629 INFO: ------------------------------------------------------------------------
2022-04-28T17:45:45.6345073Z 13:45:45.629 INFO: Total time: 5:00.567s
2022-04-28T17:45:45.6355771Z ##[error]13:45:45.629 ERROR: SonarQube server [https://<my-sonarqube-server.url>] can not be reached
2022-04-28T17:45:45.6358716Z ##[debug]Processed: ##vso[task.logissue type=error;]13:45:45.629 ERROR: SonarQube server [https://<my-sonarqube-server.url>] can not be reached
2022-04-28T17:45:45.6360263Z 13:45:45.629 ERROR: SonarQube server [<my-sonarqube-server.url>] can not be reached
2022-04-28T17:45:45.6739079Z 13:45:45.660 INFO: Final Memory: 3M/54M
2022-04-28T17:45:45.6740804Z ##[error]13:45:45.660 ERROR: Error during SonarScanner execution
2022-04-28T17:45:45.6742971Z ##[debug]Processed: ##vso[task.logissue type=error;]13:45:45.660 ERROR: Error during SonarScanner execution
2022-04-28T17:45:45.6743658Z 13:45:45.660 ERROR: Error during SonarScanner execution
2022-04-28T17:45:45.6744116Z 13:45:45.660 INFO: ------------------------------------------------------------------------
2022-04-28T17:45:45.6745198Z ##[error]org.sonarsource.scanner.api.internal.ScannerException: Unable to execute SonarScanner analysis
2022-04-28T17:45:45.6746560Z ##[debug]Processed: ##vso[task.logissue type=error;]org.sonarsource.scanner.api.internal.ScannerException: Unable to execute SonarScanner analysis
2022-04-28T17:45:45.6747432Z org.sonarsource.scanner.api.internal.ScannerException: Unable to execute SonarScanner analysis
...

Analysis: “Fail to request url”

...
2022-04-29T14:34:38.1505695Z Calling the SonarScanner CLI...
2022-04-29T14:34:38.5330753Z INFO: Scanner configuration file: C:\vsts\agent1\_work\_tasks\SonarQubePrepare_15b84ca1-b62f-4a2a-a403-89b77a063157\5.4.0\classic-sonar-scanner-msbuild\sonar-scanner-4.6.2.2472\bin\..\conf\sonar-scanner.properties
2022-04-29T14:34:38.5341815Z INFO: Project root configuration file: C:\vsts\agent1\_work\1248\.sonarqube\out\sonar-project.properties
2022-04-29T14:34:38.5922425Z INFO: SonarScanner 4.6.2.2472
2022-04-29T14:34:38.5922977Z INFO: Java 11.0.10 Oracle Corporation (64-bit)
2022-04-29T14:34:38.5923329Z INFO: Windows Server 2016 10.0 amd64
2022-04-29T14:34:38.9445913Z INFO: User cache: C:\Windows\ServiceProfiles\NetworkService\.sonar\cache
2022-04-29T14:34:39.2260841Z INFO: Scanner configuration file: C:\vsts\agent1\_work\_tasks\SonarQubePrepare_15b84ca1-b62f-4a2a-a403-89b77a063157\5.4.0\classic-sonar-scanner-msbuild\sonar-scanner-4.6.2.2472\bin\..\conf\sonar-scanner.properties
2022-04-29T14:34:39.2263474Z INFO: Project root configuration file: C:\vsts\agent1\_work\1248\.sonarqube\out\sonar-project.properties
2022-04-29T14:34:39.2597031Z INFO: Analyzing on SonarQube server 8.9.7
2022-04-29T14:34:39.2597678Z INFO: Default locale: "en_US", source code encoding: "windows-1252" (analysis is platform dependent)
2022-04-29T14:34:39.7480803Z INFO: Load global settings
2022-04-29T14:35:39.8110994Z INFO: ------------------------------------------------------------------------
2022-04-29T14:35:39.8115186Z INFO: EXECUTION FAILURE
2022-04-29T14:35:39.8116678Z INFO: ------------------------------------------------------------------------
2022-04-29T14:35:39.8117760Z INFO: Total time: 1:01.282s
2022-04-29T14:35:39.8494018Z INFO: Final Memory: 5M/54M
2022-04-29T14:35:39.8494686Z INFO: ------------------------------------------------------------------------
2022-04-29T14:35:39.8500631Z ##[error]ERROR: Error during SonarScanner execution
2022-04-29T14:35:39.8503217Z ERROR: Error during SonarScanner execution
2022-04-29T14:35:39.8504298Z ##[error]java.lang.IllegalStateException: Unable to load component class org.sonar.scanner.bootstrap.ScannerPluginInstaller
2022-04-29T14:35:39.8505810Z java.lang.IllegalStateException: Unable to load component class org.sonar.scanner.bootstrap.ScannerPluginInstaller
2022-04-29T14:35:39.8513098Z ##[error]at org.sonar.core.platform.ComponentContainer$ExtendedDefaultPicoContainer.getComponent(ComponentContainer.java:66)
2022-04-29T14:35:39.8515534Z    at org.sonar.core.platform.ComponentContainer$ExtendedDefaultPicoContainer.getComponent(ComponentContainer.java:66)
2022-04-29T14:35:39.8517515Z ##[error]at org.picocontainer.DefaultPicoContainer.getComponent(DefaultPicoContainer.java:632)
    at org.picocontainer.parameters.BasicComponentParameter$1.resolveInstance(BasicComponentParameter.java:118)
2022-04-29T14:35:39.8519702Z    at org.picocontainer.DefaultPicoContainer.getComponent(DefaultPicoContainer.java:632)
2022-04-29T14:35:39.8520500Z    at org.picocontainer.parameters.BasicComponentParameter$1.resolveInstance(BasicComponentParameter.java:118)
2022-04-29T14:35:39.8521775Z ##[error]at org.picocontainer.parameters.ComponentParameter$1.resolveInstance(ComponentParameter.java:136)
2022-04-29T14:35:39.8523646Z    at org.picocontainer.parameters.ComponentParameter$1.resolveInstance(ComponentParameter.java:136)
2022-04-29T14:35:39.8525415Z ##[error]at org.picocontainer.injectors.SingleMemberInjector.getParameter(SingleMemberInjector.java:78)
2022-04-29T14:35:39.8531072Z    at org.picocontainer.injectors.SingleMemberInjector.getParameter(SingleMemberInjector.java:78)
...
2022-04-29T14:35:39.8707192Z    at org.picocontainer.DefaultPicoContainer.getInstance(DefaultPicoContainer.java:699)
2022-04-29T14:35:39.8707784Z    at org.picocontainer.DefaultPicoContainer.getComponent(DefaultPicoContainer.java:647)
2022-04-29T14:35:39.8709861Z ##[error]at org.sonar.core.platform.ComponentContainer$ExtendedDefaultPicoContainer.getComponent(ComponentContainer.java:64)
    ... 59 more
Caused by: java.lang.IllegalStateException: Fail to request url: https://<my-sonarqube-server.url>/api/settings/values.protobuf
    at org.sonarqube.ws.client.HttpConnector.doCall(HttpConnector.java:205)
2022-04-29T14:35:39.8711519Z    at org.sonar.core.platform.ComponentContainer$ExtendedDefaultPicoContainer.getComponent(ComponentContainer.java:64)
2022-04-29T14:35:39.8712024Z    ... 59 more
2022-04-29T14:35:39.8712478Z Caused by: java.lang.IllegalStateException: Fail to request url: https://<my-sonarqube-server.url>/api/settings/values.protobuf
2022-04-29T14:35:39.8713090Z    at org.sonarqube.ws.client.HttpConnector.doCall(HttpConnector.java:205)
2022-04-29T14:35:39.8715052Z ##[error]at org.sonarqube.ws.client.HttpConnector.get(HttpConnector.java:124)
    at org.sonarqube.ws.client.HttpConnector.call(HttpConnector.java:111)
    at org.sonar.scanner.bootstrap.DefaultScannerWsClient.call(DefaultScannerWsClient.java:73)
2022-04-29T14:35:39.8716422Z    at org.sonarqube.ws.client.HttpConnector.get(HttpConnector.java:124)
2022-04-29T14:35:39.8716943Z    at org.sonarqube.ws.client.HttpConnector.call(HttpConnector.java:111)
...

Prepare: “Failed to request and parse”

...
2022-04-28T05:29:26.9514760Z ##[debug]organization=undefined
2022-04-28T05:29:26.9518463Z ##[debug][SQ] API GET: '/api/server/version' with query "undefined"
2022-04-28T05:29:27.0220157Z ##[debug]Response: 200 Body: "8.9.7.52159"
...
2022-04-28T05:29:27.5234666Z 01:29:27.517  The file SonarQube.Integration.ImportBefore.targets is up to date at C:\Windows\ServiceProfiles\NetworkService\AppData\Local\Microsoft\MSBuild\15.0\Microsoft.Common.targets\ImportBefore
2022-04-28T05:29:27.5238025Z 01:29:27.517  The file SonarQube.Integration.ImportBefore.targets is up to date at C:\Windows\ServiceProfiles\NetworkService\AppData\Local\Microsoft\MSBuild\Current\Microsoft.Common.targets\ImportBefore
2022-04-28T05:29:27.5274028Z 01:29:27.517  Installed SonarQube.Integration.targets to C:\vsts\agent1\_work\1459\.sonarqube\bin\targets
2022-04-28T05:29:27.5287115Z 01:29:27.517  Creating config and output folders...
2022-04-28T05:29:27.5300999Z 01:29:27.517  Creating directory: C:\vsts\agent1\_work\1459\.sonarqube\conf
2022-04-28T05:29:27.5307031Z 01:29:27.517  Creating directory: C:\vsts\agent1\_work\1459\.sonarqube\out
2022-04-28T05:29:27.5624559Z 01:29:27.549  Downloading from https://<my-sonarqube-server.url>/api/server/version...
2022-04-28T05:31:07.5929282Z ##[error]01:31:07.577  Failed to request and parse 'https://<my-sonarqube-server.url>/api/server/version': A task was canceled.
2022-04-28T05:31:07.5949080Z ##[debug]Processed: ##vso[task.logissue type=error;]01:31:07.577  Failed to request and parse 'https://<my-sonarqube-server.url>/api/server/version': A task was canceled.
2022-04-28T05:31:07.5950568Z 01:31:07.577  Failed to request and parse 'https://<my-sonarqube-server.url>/api/server/version': A task was canceled.
2022-04-28T05:31:07.5952112Z ##[debug]Processed: ##vso[task.logissue type=error;]
2022-04-28T05:31:07.5952420Z
2022-04-28T05:31:07.5952965Z ##[error]Unhandled Exception:
2022-04-28T05:31:07.5953797Z ##[debug]Processed: ##vso[task.logissue type=error;]Unhandled Exception:
2022-04-28T05:31:07.5977322Z ##[error]System.Threading.Tasks.TaskCanceledException: A task was canceled.
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at SonarScanner.MSBuild.PreProcessor.WebClientDownloader.<Download>d__7.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
...
1 Like

Hey there,

Looks like you’ve filed this question through your Enterprise Support as well. Please don’t cross-post – that’s double the effort on our side. :slight_smile:

We’ll handle this through ServiceDesk and if it gets solved we’ll come back with the answer so the community can also benefit!

1 Like