Slow SQL query in 9.9 LTS upgrade (on "Update profile ...")

SonarQube 9.9 LTS Upgrade
1

Upgrading SQ (Entreprise, with 50M LOC) from 9.7 to 9.9 hits some super slow queries (on Postgres 13.6) when updating the quality profiles.

Relevant SQ web logs:

2023.03.01 12:29:20 INFO web[][o.s.s.q.b.BuiltInQProfileRepositoryImpl] Load quality profiles
2023.03.01 12:29:21 INFO web[][o.s.s.q.RegisterQualityProfiles] Register quality profiles
2023.03.01 12:29:21 INFO web[][o.s.s.q.RegisterQualityProfiles] Update profile kubernetes/Sonar way
2023.03.01 12:29:21 INFO web[][o.s.s.q.RegisterQualityProfiles] Update profile css/Sonar way
2023.03.01 12:41:53 INFO web[][o.s.s.q.RegisterQualityProfiles] Update profile scala/Sonar way
2023.03.01 12:41:53 INFO web[][o.s.s.q.RegisterQualityProfiles] Update profile scala/FindBugs Security Scala
2023.03.01 12:41:53 INFO web[][o.s.s.q.RegisterQualityProfiles] Update profile jsp/Sonar way
2023.03.01 12:41:53 INFO web[][o.s.s.q.RegisterQualityProfiles] Update profile jsp/FindBugs Security JSP
2023.03.01 12:41:53 INFO web[][o.s.s.q.RegisterQualityProfiles] Update profile js/Sonar way
2023.03.01 12:49:36 INFO web[][o.s.s.q.RegisterQualityProfiles] Update profile py/Sonar way
2023.03.01 12:55:59 INFO web[][o.s.s.q.RegisterQualityProfiles] Update profile apex/Sonar way
2023.03.01 12:55:59 INFO web[][o.s.s.q.RegisterQualityProfiles] Update profile plsql/Sonar way
2023.03.01 12:55:59 INFO web[][o.s.s.q.RegisterQualityProfiles] Register profile docker/Sonar way
2023.03.01 12:55:59 INFO web[][o.s.s.q.RegisterQualityProfiles] Update profile java/Sonar way
2023.03.01 13:01:49 INFO web[][o.s.s.q.RegisterQualityProfiles] Update profile java/FindBugs
2023.03.01 13:01:49 INFO web[][o.s.s.q.RegisterQualityProfiles] Update profile java/FindBugs + FB-Contrib
2023.03.01 13:01:49 INFO web[][o.s.s.q.RegisterQualityProfiles] Update profile java/FindBugs Security Audit
2023.03.01 13:01:49 INFO web[][o.s.s.q.RegisterQualityProfiles] Update profile java/FindBugs Security Minimal
2023.03.01 13:01:49 INFO web[][o.s.s.q.RegisterQualityProfiles] Update profile web/Sonar way
2023.03.01 13:07:37 INFO web[][o.s.s.q.RegisterQualityProfiles] Update profile flex/Sonar way
2023.03.01 13:07:37 INFO web[][o.s.s.q.RegisterQualityProfiles] Update profile xml/Sonar way
2023.03.01 13:07:37 INFO web[][o.s.s.q.RegisterQualityProfiles] Update profile json/Sonar way
2023.03.01 13:07:37 INFO web[][o.s.s.q.RegisterQualityProfiles] Update profile text/Sonar way
2023.03.01 13:07:37 INFO web[][o.s.s.q.RegisterQualityProfiles] Update profile vbnet/Sonar way
2023.03.01 13:13:21 INFO web[][o.s.s.q.RegisterQualityProfiles] Update profile grvy/Sonar way
2023.03.01 13:13:21 INFO web[][o.s.s.q.RegisterQualityProfiles] Update profile cloudformation/Sonar way
2023.03.01 13:13:21 INFO web[][o.s.s.q.RegisterQualityProfiles] Update profile swift/Sonar way
2023.03.01 13:13:21 INFO web[][o.s.s.q.RegisterQualityProfiles] Update profile yaml/YAML Analyzer
2023.03.01 13:13:21 INFO web[][o.s.s.q.RegisterQualityProfiles] Update profile yaml/Sonar way
2023.03.01 13:13:21 INFO web[][o.s.s.q.RegisterQualityProfiles] Update profile cpp/Sonar way
2023.03.01 13:19:04 INFO web[][o.s.s.q.RegisterQualityProfiles] Update profile c/Sonar way
2023.03.01 13:24:48 INFO web[][o.s.s.q.RegisterQualityProfiles] Update profile kotlin/Sonar way

(that’s almost one hour for updating all the profiles)

Sample slow query reported in Postgres (13.6) logs, for ~200M rows in live_measures:

2023-03-01 12:41:52.121 UTC:10.228.202.47(46904):sonarqube@sonarqube:[263794]:LOG:  duration: 751038.179 ms  execute <unnamed>: select
	      lm.project_uuid
	    from
	      live_measures lm
	    inner join
	      metrics m on m.uuid = lm.metric_uuid
	    where
	      m.name = 'ncloc_language_distribution'
	      and lm.component_uuid = lm.project_uuid
	      and lm.project_uuid not in (select project_uuid from project_qprofiles)
	      and
	       (  
	        lm.text_value like $1 escape '/'
	        or  
	        lm.text_value like $2 escape '/'
	       )
2023-03-01 12:41:52.143 UTC:10.228.202.47(46904):sonarqube@sonarqube:[263794]:LOG:  duration: 751038.164 ms  plan:
	Query Text: select
	      lm.project_uuid
	    from
	      live_measures lm
	    inner join
	      metrics m on m.uuid = lm.metric_uuid
	    where
	      m.name = 'ncloc_language_distribution'
	      and lm.component_uuid = lm.project_uuid
	      and lm.project_uuid not in (select project_uuid from project_qprofiles)
	      and
	       (  
	        lm.text_value like $1 escape '/'
	        or  
	        lm.text_value like $2 escape '/'
	       )
	Nested Loop  (cost=8.62..4988099.82 rows=2 width=21)
	  ->  Index Scan using metrics_unique_name on metrics m  (cost=0.15..2.37 rows=1 width=6)
	        Index Cond: ((name)::text = 'ncloc_language_distribution'::text)
	  ->  Index Scan using live_measures_component on live_measures lm  (cost=8.47..4988097.40 rows=6 width=23)
	        Index Cond: ((metric_uuid)::text = (m.uuid)::text)
	        Filter: ((NOT (hashed SubPlan 1)) AND ((component_uuid)::text = (project_uuid)::text) AND (((text_value)::text ~~ 'css=%'::text) OR ((text_value)::text ~~ '%;css=%'::text)))
	        SubPlan 1
	          ->  Seq Scan on project_qprofiles  (cost=0.00..7.12 rows=312 width=21)

I’ve opened a PR to (significantly) improve that: SonarSource/sonarqube#3319. Assuming it’s okay and gets merged, it would be amazing to get it backported to some 9.9.1 release (we would happily delay our actual 9.9.x migration if it spares one hour of downtime).

2 Likes
8

Hi @thomasgl-orange

Thank you for your PR, it has been merged and it will be released with the next version on SonarQube(10.0)
Regarding backporting to the LTS, we’ll need to discuss it within the team. We’ll let you know when we know more.

2 Likes
11

Hi @thomasgl-orange,

I’m afraid this change didn’t qualify for backporting to the LTS release. It will only be available in versions 10.0+.

1 Like