I'm attempting to upgrade a 5.6.1 sonarqube instance to 6.5, it runs on linux against an Oracle database.
I have added the following plugins;
- groovy 1.5
- ldap 2.2.0.608
oracle driver is ojdbc6-11.2.0.2.0 jdk is 1.8.0_144
the process(es) start but the web one simply hangs. I have added TRACE logging and see
2017.09.07 22:07:02 TRACE web[][o.s.s.p.Platform] level1 started | time=2286ms
2017.09.07 22:07:02 TRACE web[][o.s.s.p.Platform] level2 configured | time=33ms
then nothing until
2017.09.07 23:47:53 TRACE web[][o.s.c.p.ComponentContainer] org.sonar.server.platform.db.migration.history.MigrationHistoryTableImpl started | time=2139938ms
2017.09.08 00:27:00 TRACE web[][o.s.c.p.ComponentContainer] org.sonar.server.platform.db.migration.history.MigrationHistoryImpl started | time=2347061ms
2017.09.08 00:27:00 TRACE web[][sql] time=4ms | sql=select version from schema_migrations
2017.09.08 00:27:00 TRACE web[][sql] time=2ms | sql=select version from schema_migrations
2017.09.08 00:27:00 WARN web[][o.s.s.p.DatabaseServerCompatibility] Database must be upgraded. Please backup database and browse /setup
This same slowness continues once the migration starts, for example
2017.09.08 17:06:45 INFO web[][o.s.s.p.d.m.v.v.DropRelatedDashboardTables] Removing tables [widget_properties, widgets, active_dashboards, dashboards]
2017.09.08 17:06:45 TRACE web[][sql] time=35ms | sql=BEGIN EXECUTE IMMEDIATE 'DROP SEQUENCE widget_properties_seq'; EXCEPTION WHEN OTHERS THEN IF SQLCODE != -2289 THEN RAISE; END IF; END;
2017.09.08 17:06:45 TRACE web[][sql] time=19ms | sql=BEGIN EXECUTE IMMEDIATE 'DROP TRIGGER widget_properties_idt'; EXCEPTION WHEN OTHERS THEN IF SQLCODE != -4080 THEN RAISE; END IF; END;
2017.09.08 17:06:45 TRACE web[][sql] time=87ms | sql=DROP TABLE widget_properties
2017.09.08 17:06:45 TRACE web[][sql] time=12ms | sql=BEGIN EXECUTE IMMEDIATE 'DROP SEQUENCE widgets_seq'; EXCEPTION WHEN OTHERS THEN IF SQLCODE != -2289 THEN RAISE; END IF; END;
2017.09.08 17:06:45 TRACE web[][sql] time=16ms | sql=BEGIN EXECUTE IMMEDIATE 'DROP TRIGGER widgets_idt'; EXCEPTION WHEN OTHERS THEN IF SQLCODE != -4080 THEN RAISE; END IF; END;
2017.09.08 17:06:45 TRACE web[][sql] time=43ms | sql=DROP TABLE widgets
2017.09.08 17:06:45 TRACE web[][sql] time=11ms | sql=BEGIN EXECUTE IMMEDIATE 'DROP SEQUENCE active_dashboards_seq'; EXCEPTION WHEN OTHERS THEN IF SQLCODE != -2289 THEN RAISE; END IF; END;
2017.09.08 17:06:45 TRACE web[][sql] time=27ms | sql=BEGIN EXECUTE IMMEDIATE 'DROP TRIGGER active_dashboards_idt'; EXCEPTION WHEN OTHERS THEN IF SQLCODE != -4080 THEN RAISE; END IF; END;
2017.09.08 17:06:45 TRACE web[][sql] time=64ms | sql=DROP TABLE active_dashboards
2017.09.08 17:06:45 TRACE web[][sql] time=12ms | sql=BEGIN EXECUTE IMMEDIATE 'DROP SEQUENCE dashboards_seq'; EXCEPTION WHEN OTHERS THEN IF SQLCODE != -2289 THEN RAISE; END IF; END;
2017.09.08 17:06:45 TRACE web[][sql] time=19ms | sql=BEGIN EXECUTE IMMEDIATE 'DROP TRIGGER dashboards_idt'; EXCEPTION WHEN OTHERS THEN IF SQLCODE != -4080 THEN RAISE; END IF; END;
2017.09.08 17:06:45 TRACE web[][sql] time=37ms | sql=DROP TABLE dashboards
2017.09.08 17:06:45 TRACE web[][sql] time=6ms | sql=insert into schema_migrations(version) values (?) | params=1420
2017.09.08 17:06:45 INFO web[][DbMigrations] #1420 'Drop tables related to dashboards': success | time=8515237ms
2017.09.08 17:06:45 INFO web[][DbMigrations] #1421 'Drop tables related to measure filters'...
i.e. a significant number of operations appear to take hour(s) to perform
What could cause such slow performance? There are no hints in the logs to give an idea as to what it is doing as the actual query execution time appears low.
The root cause of this problem turned out to be badly performing data dictionary queries, one example was a query like
This was not seen in sonarqube 5.6.