Upgrade from SonarQube 8.9.9 to 9.9.2 causes MSSQL deadlocks

Hi,

After upgrading from SonarQube 8.9.9 Community to 9.9.2 we see MSSQL deadlocks in our logs:

"### SQL: delete from properties where prop_key=? and component_uuid=? and user_uuid is null

Cause: com.microsoft.sqlserver.jdbc.SQLServerException: Transaction (Process ID 80) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction."

We are running SonarQube on Debian Bullseye11.5, which is using OpenJDK Runtime Environment (build 17.0.6+10-LTS)
We use MSSQL 2016 as our database server.

We followed your best practices to enable is_read_committed_snapshot_on=true on the database, suggested in your installation, In another article (MSSQL DeadLock with workerCount ) a user suggested that setting sonar.ce.workerCount=1 had helped him getting rid of these errors, but after doing that we still see these errors. What makes me scratch my head is “delete from properties where prop_key=? and component_uuid=? and user_uuid is null” which in my opinion would never delete anything, and when i asked my DBA what such a query would do he responded “I would expect it to fail due to syntax error. Query parser can not parse that statement with question marks”.

Is sonarqube failing to log the correct values in the query, or might our database have been corrupted during the upgrade?

Any insight would help us tremendously

Kind regards,

Jonas

Hey there.

Those question marks bit misleading – they aren’t literally being passed to the database server like that.

Is READ_COMMITTED_SNAPSHOT set on your SQL server as documented? This not being set is the most common cause of deadlocks.

Hi,

Yes, it is indeed.

Kind regards

Jonas

Thanks. I actually missed that part in your first message.

  • Is your SQL Server performing well? Regarding CPU, memory, disk space…
  • Are you database indexes/statistics up-to-date?

And to be super clear, you have READ_COMMITTED_SNAPSHOT set to 1, not is_read_committed_snapshot_on set to true, correct?

Nope, thats a typo on my behalf.

Just to be sure i will verify it with the DBAs

I can confirm from the DBA who did the change, that it’s indeed set correctly:

READ_COMMITTED_SNAPSHOT=1

On that database.

Kind regards,

Jonas

Hi all,

This error still persists on sonar after all this time. Last weekend we upgraded sonarqube to 9.9.8 in the hope that this was something caused by the database connector or some obscure bug in sonar, however we still see the same issues;



2025.01.21 16:08:08 ERROR web[AZR51aUxegWV2rC8F+fZ][o.s.s.w.WebServiceEngine] Fail to process request http://SONARURL/api/settings/set?component=com.ponent%3AAPPNAME%3Abugfix-CPIT-11630_alt&key=sonar.core.startTime&value=2022-08-12T17%3A41%3A54%2B0200
org.apache.ibatis.exceptions.PersistenceException:

Error updating database. Cause: com.microsoft.sqlserver.jdbc.SQLServerException: Transaction (Process ID 303) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.

The error may exist in org.sonar.db.property.PropertiesMapper

The error may involve org.sonar.db.property.PropertiesMapper.delete-Inline

The error occurred while setting parameters

SQL: delete from properties where prop_key=? and component_uuid=? and user_uuid is null

Cause: com.microsoft.sqlserver.jdbc.SQLServerException: Transaction (Process ID 303) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.



Caused by: com.microsoft.sqlserver.jdbc.SQLServerException: Transaction (Process ID 303) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.

As verified in this thread before, we indeed have READ_COMMITTED_SNAPSHOT=1 on the database, for both our enterprise and community version of sonarcube, however we only see this issue on sonarqube community 9.9.8

Any help would make this application a ton more useful to us, has anyone ran into the same issue?

Kindest of regards
Jonas

Hey @Jonasandersson

I’m actually really puzzled by this specific web request.

sonar.core.startTime is a global server setting that has no business being set via Web API (like its name would lead you to believe, it’s set at start time), and certainly not tied to a specific component.

Where is this web request coming from? You should be able to hunt it down by looking at your access.log file. Do you see any other weird requests from the same origin / user agent?

What I’m trying to get at is that if something (bad actor, internal automation gone rogue) is flooding your SonarQube server with bad requests, it’s not unreasonable that some erroneous behavior would follow.

Hi Colin,

And thanks for the very fast response. As suspected, this request came from Bitbucket Datacenter v8.19.14, which uses the Mibex Include Code Quality for Bitbucket (version 7.2.0), which according to Mibex:
supports SonarQube™ compatibility:

  • v7.7 or newer
  • Community, Commercial editions and SonarCloud™ support

The request doesn’t come alone, here are some other request that happens before and after:

<Bitbucket.IP> - - [21/Jan/2025:16:08:08 +0100] “POST /api/settings/set?component=com..cockpit.appserver.tradingengine%3Acockpit-trading-engine-app-server%3Abugfix-CPIT-11630_alt&key=sonar.auth.saml.user.name&value=http%3A%2F%2Fschemas.microsoft.com%2Fidentity%2Fclaims%2Fdisplayname HTTP/1.1” 400 914 “-” “Apache-HttpClient/4.5.14 (Java/17.0.13)”
<Bitbucket.IP> - - [21/Jan/2025:16:08:07 +0100] “POST /api/settings/set?component=com..cockpit.appserver.tradingengine%3Acockpit-trading-engine-app-server%3Abugfix-CPIT-11630_alt&key=sonar.core.id&value=F390DDA4-AYHif_UzsJTGt-y94WVk HTTP/1.1” 204 1632 “-” “Apache-HttpClient/4.5.14 (Java/17.0.13)”
<Bitbucket.IP> - - [21/Jan/2025:16:08:07 +0100] “POST /api/settings/set?component=com..cockpit.appserver.tradingengine%3Acockpit-trading-engine-app-server%3Abugfix-CPIT-11630_alt&key=sonar.coverage.jacoco.xmlReportPaths&values=target%2Fsite%2Fjacoco-aggregate%2Fjacoco.xml&values=target%2Fsite%2Fjacoco%2Fjacoco.xml HTTP/1.1” 204 1632 “-” “Apache-HttpClient/4.5.14 (Java/17.0.13)”
<Bitbucket.IP> - - [21/Jan/2025:16:08:08 +0100] “POST /api/settings/set?component=com..cockpit.appserver.tradingengine%3Acockpit-trading-engine-app-server%3Abugfix-CPIT-11630_alt&key=sonar.auth.saml.user.login&value=http%3A%2F%2Fschemas.xmlsoap.org%2Fws%2F2005%2F05%2Fidentity%2Fclaims%2Fonprem_sam_account_name%2FsamAccountName HTTP/1.1” 400 367 “-” “Apache-HttpClient/4.5.14 (Java/17.0.13)”
<Bitbucket.IP> - - [21/Jan/2025:16:08:08 +0100] “GET /api/qualityprofiles/search?projectKey=com..cockpit.appserver.tradingengine%3Acockpit-trading-engine-app-server%3Abugfix-CPIT-11630_alt HTTP/1.1” 200 2973 “-” “Apache-HttpClient/4.5.14 (Java/17.0.13)”
<Bitbucket.IP> - - [21/Jan/2025:16:08:08 +0100] “GET /api/projects/search?projects=com..cockpit.rfqenrichmentservice%3Acockpit-rfq-enrichment-service%3Afeature-CPIT-11497 HTTP/1.1” 200 1986 “-” “Apache-HttpClient/4.5.14 (Java/17.0.13)”
<Bitbucket.IP> - - [21/Jan/2025:16:08:08 +0100] “GET /api/qualityprofiles/search?projectKey=com..cockpit.appserver.tradingengine%3Acockpit-trading-engine-app-server%3Amaster HTTP/1.1” 200 2424 “-” “Apache-HttpClient/4.5.14 (Java/17.0.13)”
<Bitbucket.IP> - - [21/Jan/2025:16:08:08 +0100] “POST /api/settings/set?component=com..cockpit.appserver.tradingengine%3Acockpit-trading-engine-app-server%3Abugfix-CPIT-11630_alt&key=sonaranalyzer-cs.nuget.packageVersion&value=8.51.0.59060 HTTP/1.1” 400 378 “-” “Apache-HttpClient/4.5.14 (Java/17.0.13)”
<Bitbucket.IP> - - [21/Jan/2025:16:08:06 +0100] “POST /api/settings/set?component=com..cockpit.appserver.tradingengine%3Acockpit-trading-engine-app-server%3Abugfix-CPIT-11630_alt&key=sonar.issue.ignore.allfile&fieldValues=%7B%22fileRegexp%22%3A%22%2F%2F+Generated+by+the+protocol+buffer+compiler.++DO+NOT+EDIT%22%7D HTTP/1.1” 204 1632 “-” “Apache-HttpClient/4.5.14 (Java/17.0.13)”
<Bitbucket.IP> - - [21/Jan/2025:16:08:07 +0100] “POST /api/settings/set?component=com..cockpit.appserver.tradingengine%3Acockpit-trading-engine-app-server%3Abugfix-CPIT-11630_alt&key=sonar.terraform.file.suffixes&values=.tf HTTP/1.1” 204 1632 “-” “Apache-HttpClient/4.5.14 (Java/17.0.13)”
<Bitbucket.IP> - - [21/Jan/2025:16:08:07 +0100] “POST /api/settings/set?component=com..cockpit.appserver.tradingengine%3Acockpit-trading-engine-app-server%3Abugfix-CPIT-11630_alt&key=sonar.ruby.file.suffixes&values=.rb HTTP/1.1” 204 1632 “-” “Apache-HttpClient/4.5.14 (Java/17.0.13)”
<Bitbucket.IP> - - [21/Jan/2025:16:08:09 +0100] “POST /api/settings/set?component=com..cockpit.appserver.tradingengine%3Acockpit-trading-engine-app-server%3Abugfix-CPIT-11630_alt&key=sonaranalyzer-cs.nuget.packageVersion&value=8.51.0.59060 HTTP/1.1” 400 378 “-” “Apache-HttpClient/4.5.14 (Java/17.0.13)”
<Bitbucket.IP> - - [21/Jan/2025:16:08:07 +0100] “POST /api/settings/set?component=com..cockpit.appserver.tradingengine%3Acockpit-trading-engine-app-server%3Abugfix-CPIT-11630_alt&key=sonar.terraform.file.suffixes&values=.tf HTTP/1.1” 204 1632 “-” “Apache-HttpClient/4.5.14 (Java/17.0.13)”
<Bitbucket.IP> - - [21/Jan/2025:16:08:09 +0100] “POST /api/settings/set?component=com..cockpit.appserver.tradingengine%3Acockpit-trading-engine-app-server%3Abugfix-CPIT-11630_alt&key=sonar.auth.github.allowUsersToSignUp&value=true HTTP/1.1” 400 926 “-” “Apache-HttpClient/4.5.14 (Java/17.0.13)”
<Bitbucket.IP> - - [21/Jan/2025:16:08:09 +0100] “GET /api/qualitygates/get_by_project?project=com..cockpit.appserver.tradingengine%3Acockpit-trading-engine-app-server%3Amaster HTTP/1.1” 200 1321 “-” “Apache-HttpClient/4.5.14 (Java/17.0.13)”

So you are suggesting the plugin should not expect these requests to work, and we might want to talk to Mibex about the plugin and the issue it creates?

Kindest of regards
Jonas

Another thing that strikes me as odd is that the request is recieved and then gets a 400 (bad request) however, sonarcube still seems to process it, as if it was a good request, example here:

2025.01.21 17:23:46 ERROR web[AZR51aUxegWV2rC8GNMv][o.s.s.w.WebServiceEngine] Fail to process request http:///api/settings/set?component=com.company.tradestore
.enrichment%3Atradestore-enrichment-parent%3Afeature-TCAP-4205-ThroughtputTest&key=sonar.dbcleaner.daysBeforeDeletingClosedIssues&value=30
org.apache.ibatis.exceptions.PersistenceException:

Error updating database. Cause: com.microsoft.sqlserver.jdbc.SQLServerException: Transaction (Process ID 303) was deadlocked on lock resources with another process and has been chosen

as the deadlock victim. Rerun the transaction.

The error may exist in org.sonar.db.property.PropertiesMapper

The error may involve org.sonar.db.property.PropertiesMapper.delete-Inline

The error occurred while setting parameters

SQL: delete from properties where prop_key=? and component_uuid=? and user_uuid is null

Cause: com.microsoft.sqlserver.jdbc.SQLServerException: Transaction (Process ID 303) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Re

run the transaction.
at org.apache.ibatis.exceptions.ExceptionFactory.wrapException(ExceptionFactory.java:30)
at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:196)
at org.apache.ibatis.session.defaults.DefaultSqlSession.delete(DefaultSqlSession.java:209)

If it was a completely bad request would it not be dismissed as a wrongful request?

Kind regards

Jonas