Database migration in a 5.6.1 to 6.5 upgrade is exceptionally slow

335 views Asked by At

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.

1

There are 1 answers

0
Matt On BEST ANSWER

The root cause of this problem turned out to be badly performing data dictionary queries, one example was a query like

SELECT NULL AS table_cat, 
     o.owner AS table_schem, 
     o.object_name AS table_name, 
     o.object_type AS table_type, 
     NULL AS remarks 
FROM all_objects o 
WHERE     o.owner LIKE :1 ESCAPE '/' 
     AND o.object_name LIKE :2 ESCAPE '/' 
     AND o.object_type IN ('xxx', 'TABLE') 
ORDER BY table_type, table_schem, table_name 

This was not seen in sonarqube 5.6.