SonarQube 7.3 database upgrade failed on #2114 'Add unique indexes on table users'


(Rémi Roques) #1

Hi there,

Our upgrade from SonarQube 7.1 to 7.3 Community Edition failed with the following error message in the logs:

2018.09.16 22:08:53 INFO  web[][o.s.p.ProcessEntryPoint] Starting web
2018.09.16 22:08:54 INFO  web[][o.a.t.u.n.NioSelectorPool] Using a shared selector for servlet write/read
2018.09.16 22:08:55 INFO  web[][o.s.c.e.CoreExtensionsLoader] Loaded core extensions: 
2018.09.16 22:08:55 INFO  web[][o.e.p.PluginsService] no modules loaded
2018.09.16 22:08:55 INFO  web[][o.e.p.PluginsService] loaded plugin [org.elasticsearch.join.ParentJoinPlugin]
2018.09.16 22:08:55 INFO  web[][o.e.p.PluginsService] loaded plugin [org.elasticsearch.percolator.PercolatorPlugin]
2018.09.16 22:08:55 INFO  web[][o.e.p.PluginsService] loaded plugin [org.elasticsearch.transport.Netty4Plugin]
2018.09.16 22:08:57 INFO  web[][o.s.s.e.EsClientProvider] Connected to local Elasticsearch: [127.0.0.1:9001]
2018.09.16 22:08:57 INFO  web[][o.s.s.p.LogServerVersion] SonarQube Server / 7.3.0.15553 / 7f72262e02808e9431d97735ece621a22a1d8208
2018.09.16 22:08:57 INFO  web[][o.sonar.db.Database] Create JDBC data source for REDACTED 
2018.09.16 22:08:58 WARN  web[][o.s.d.DatabaseChecker] MySQL support is deprecated and will be dropped soon.
2018.09.16 22:08:59 INFO  web[][o.s.s.p.ServerFileSystemImpl] SonarQube home: /opt/sonarqube-7.3
2018.09.16 22:08:59 INFO  web[][o.s.s.u.SystemPasscodeImpl] System authentication by passcode is disabled
2018.09.16 22:09:00 WARN  web[][o.s.s.p.DatabaseServerCompatibility] Database must be upgraded. Please backup database and browse /setup
2018.09.16 22:09:00 INFO  web[][o.s.s.p.ServerPluginRepository] Deploy plugin Azure Active Directory (AAD) Authentication Plug-in for SonarQube / 1.0
2018.09.16 22:09:00 INFO  web[][o.s.s.p.ServerPluginRepository] Deploy plugin Checkstyle / 4.11 / 
2018.09.16 22:09:00 INFO  web[][o.s.s.p.ServerPluginRepository] Deploy plugin Git / 1.4.1.1128 / e051f5aeb379541b13956447b5dc8b4e0b23b098
2018.09.16 22:09:00 INFO  web[][o.s.s.p.ServerPluginRepository] Deploy plugin LDAP / 2.2.0.608 / 79dc3fa4393a29667673c70182f3016288b548b7
2018.09.16 22:09:00 INFO  web[][o.s.s.p.ServerPluginRepository] Deploy plugin SonarC# / 7.3.2.6129 / e7a731061a7fa928c4e1c11b830f22db97a61f83
2018.09.16 22:09:00 INFO  web[][o.s.s.p.ServerPluginRepository] Deploy plugin SonarCSS / 1.0.1.508 / 2eb799e363666ae65036ad61a6e6adc1a1283097
    2018.09.16 22:09:00 INFO  web[][o.s.s.p.ServerPluginRepository] Deploy plugin SonarFlex / 2.4.0.1222 / 68d9cb3b7daccbc4869c4f2b89d09218d26a0829
2018.09.16 22:09:00 INFO  web[][o.s.s.p.ServerPluginRepository] Deploy plugin SonarGo / 1.1.0.1612 / 1809c7be6d88396c0a1b8d597b1e9e0ed8d29730
2018.09.16 22:09:00 INFO  web[][o.s.s.p.ServerPluginRepository] Deploy plugin SonarJS / 4.2.0.6476 / a21b56462f3375b5d51d90f1819862878476d817
2018.09.16 22:09:00 INFO  web[][o.s.s.p.ServerPluginRepository] Deploy plugin SonarJava / 5.6.1.15064 / dd4545a04af6f7d0cb0486926cfa8cfc5cae5ee1
2018.09.16 22:09:00 INFO  web[][o.s.s.p.ServerPluginRepository] Deploy plugin SonarKotlin / 1.0.1.965 / b5872affdfeda52e0a71494e2df9a3524b80d3bc
2018.09.16 22:09:00 INFO  web[][o.s.s.p.ServerPluginRepository] Deploy plugin SonarPHP / 2.14.0.3569 / 59a202b8d1c5276ce32da2a0bc63c94cae4cdeb2
2018.09.16 22:09:00 INFO  web[][o.s.s.p.ServerPluginRepository] Deploy plugin SonarPython / 1.10.0.2131 / a00e0ddc83bbeb01a9ee7475fab9eafe3f4096ac
2018.09.16 22:09:00 INFO  web[][o.s.s.p.ServerPluginRepository] Deploy plugin SonarTS / 1.7.0.2893 / 0d296cae94240b183a0b3ae6e1a409a60fe9f865
2018.09.16 22:09:00 INFO  web[][o.s.s.p.ServerPluginRepository] Deploy plugin SonarXML / 1.5.1.1452 / eadc1dcd0e24a3c77068e3c1d41af0327d6b16ea
2018.09.16 22:09:00 INFO  web[][o.s.s.p.ServerPluginRepository] Deploy plugin Svn / 1.8.0.1168 / 4143f2d119022a758f6bf40aed4294e4c31706cf
2018.09.16 22:09:02 INFO  web[][o.s.s.p.Platform] Database needs migration
2018.09.16 22:09:02 INFO  web[][o.s.s.p.w.MasterServletFilter] Initializing servlet filter org.sonar.server.ws.WebServiceFilter@6d23ba3f [pattern=UrlPattern{inclusions=[/api/system/migrate_db.*, ...], exclusions=[/api/properties*, ...]}]
2018.09.16 22:09:02 INFO  web[][o.s.s.a.EmbeddedTomcat] HTTP connector enabled on port 9000
2018.09.16 22:25:11 INFO  web[][o.s.s.p.d.m.DatabaseMigrationImpl] Starting DB Migration and container restart
2018.09.16 22:25:11 INFO  web[][DbMigrations] Executing DB migrations...
2018.09.16 22:25:11 INFO  web[][DbMigrations] #2100 'Increase size of USERS.CRYPTED_PASSWORD'...
2018.09.16 22:25:11 INFO  web[][DbMigrations] #2100 'Increase size of USERS.CRYPTED_PASSWORD': success | time=244ms
2018.09.16 22:25:11 INFO  web[][DbMigrations] #2101 'Add HASH_METHOD to table users'...
2018.09.16 22:25:11 INFO  web[][DbMigrations] #2101 'Add HASH_METHOD to table users': success | time=62ms
2018.09.16 22:25:11 INFO  web[][DbMigrations] #2102 'Populate HASH_METHOD on table users'...
2018.09.16 22:25:11 INFO  web[][DbMigrations] #2102 'Populate HASH_METHOD on table users': success | time=36ms
2018.09.16 22:25:11 INFO  web[][DbMigrations] #2103 'Add isExternal boolean to rules'...
2018.09.16 22:25:12 INFO  web[][DbMigrations] #2103 'Add isExternal boolean to rules': success | time=388ms
2018.09.16 22:25:12 INFO  web[][DbMigrations] #2104 'Create ALM_APP_INSTALLS table'...
2018.09.16 22:25:12 INFO  web[][DbMigrations] #2104 'Create ALM_APP_INSTALLS table': success | time=125ms
2018.09.16 22:25:12 INFO  web[][DbMigrations] #2105 'Add LINE_HASHES_VERSION to table FILE_SOURCES'...
2018.09.16 22:25:29 INFO  web[][DbMigrations] #2105 'Add LINE_HASHES_VERSION to table FILE_SOURCES': success | time=17022ms
2018.09.16 22:25:29 INFO  web[][DbMigrations] #2106 'Create PROJECT_MAPPINGS table'...
2018.09.16 22:25:29 INFO  web[][DbMigrations] #2106 'Create PROJECT_MAPPINGS table': success | time=104ms
2018.09.16 22:25:29 INFO  web[][DbMigrations] #2107 'Add UUID on table USERS'...
2018.09.16 22:25:29 INFO  web[][DbMigrations] #2107 'Add UUID on table USERS': success | time=59ms
2018.09.16 22:25:29 INFO  web[][DbMigrations] #2108 'Populate USERS.UUID with USERS.LOGIN'...
2018.09.16 22:25:29 INFO  web[][o.s.s.p.d.m.s.MassUpdate] 56 users processed (0 items/sec)
2018.09.16 22:25:29 INFO  web[][DbMigrations] #2108 'Populate USERS.UUID with USERS.LOGIN': success | time=85ms
2018.09.16 22:25:29 INFO  web[][DbMigrations] #2109 'Add EXTERNAL_ID on table users'...
2018.09.16 22:25:29 INFO  web[][DbMigrations] #2109 'Add EXTERNAL_ID on table users': success | time=46ms
2018.09.16 22:25:29 INFO  web[][DbMigrations] #2110 'Rename EXTERNAL_IDENTITY to EXTERNAL_LOGIN on table users'...
2018.09.16 22:25:29 INFO  web[][DbMigrations] #2110 'Rename EXTERNAL_IDENTITY to EXTERNAL_LOGIN on table users': success | time=24ms
2018.09.16 22:25:29 INFO  web[][DbMigrations] #2111 'Update null values from external columns and login of users'...
2018.09.16 22:25:29 INFO  web[][o.s.s.p.d.m.s.MassUpdate] 30 users processed (0 items/sec)
2018.09.16 22:25:29 INFO  web[][DbMigrations] #2111 'Update null values from external columns and login of users': success | time=53ms
2018.09.16 22:25:29 INFO  web[][DbMigrations] #2112 'Populate EXTERNAL_ID on table users'...
2018.09.16 22:25:29 INFO  web[][o.s.s.p.d.m.s.MassUpdate] 56 users processed (0 items/sec)
2018.09.16 22:25:29 INFO  web[][DbMigrations] #2112 'Populate EXTERNAL_ID on table users': success | time=50ms
2018.09.16 22:25:29 INFO  web[][DbMigrations] #2113 'Makes same columns of table users not nullable'...
2018.09.16 22:25:29 INFO  web[][DbMigrations] #2113 'Makes same columns of table users not nullable': success | time=76ms
2018.09.16 22:25:29 INFO  web[][DbMigrations] #2114 'Add unique indexes on table users'...
2018.09.16 22:25:29 ERROR web[][DbMigrations] #2114 'Add unique indexes on table users': failure | time=56ms
2018.09.16 22:25:29 ERROR web[][DbMigrations] Executed DB migrations: failure | time=18444ms
2018.09.16 22:25:29 ERROR web[][o.s.s.p.d.m.DatabaseMigrationImpl] DB migration failed | time=18588ms
2018.09.16 22:25:29 ERROR web[][o.s.s.p.d.m.DatabaseMigrationImpl] DB migration ended with an exception
org.sonar.server.platform.db.migration.step.MigrationStepExecutionException: Execution of migration step #2114 'Add unique indexes on table users' failed
at         org.sonar.server.platform.db.migration.step.MigrationStepsExecutorImpl.execute(MigrationStepsExecutorImpl.java:79)
at     org.sonar.server.platform.db.migration.step.MigrationStepsExecutorImpl.execute(MigrationStepsExecutorImpl.java:67)
at java.lang.Iterable.forEach(Iterable.java:75)
at     org.sonar.server.platform.db.migration.step.MigrationStepsExecutorImpl.execute(MigrationStepsExecutorImpl.java:52)
at org.sonar.server.platform.db.migration.engine.MigrationEngineImpl.execute(MigrationEngineImpl.java:68)
at org.sonar.server.platform.db.migration.DatabaseMigrationImpl.doUpgradeDb(DatabaseMigrationImpl.java:105)
at org.sonar.server.platform.db.migration.DatabaseMigrationImpl.doDatabaseMigration(DatabaseMigrationImpl.java:80)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.IllegalStateException: Fail to execute CREATE UNIQUE INDEX uniq_external_id ON users (external_identity_provider, external_id)
at org.sonar.server.platform.db.migration.step.DdlChange$Context.execute(DdlChange.java:97)
at org.sonar.server.platform.db.migration.step.DdlChange$Context.execute(DdlChange.java:77)
at org.sonar.server.platform.db.migration.step.DdlChange$Context.execute(DdlChange.java:117)
at org.sonar.server.platform.db.migration.version.v72.AddUniqueIndexesOnUsers.execute(AddUniqueIndexesOnUsers.java:45)
at org.sonar.server.platform.db.migration.step.DdlChange.execute(DdlChange.java:45)
at org.sonar.server.platform.db.migration.step.MigrationStepsExecutorImpl.execute(MigrationStepsExecutorImpl.java:75)
... 9 common frames omitted
Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: Duplicate entry 'aad-Azure AD' for key 'uniq_external_id'
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at com.mysql.jdbc.Util.handleNewInstance(Util.java:425)
at com.mysql.jdbc.Util.getInstance(Util.java:408)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:936)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3976)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3912)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2530)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2683)
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2482)
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2440)
at com.mysql.jdbc.StatementImpl.executeInternal(StatementImpl.java:845)
at com.mysql.jdbc.StatementImpl.execute(StatementImpl.java:745)
at org.apache.commons.dbcp.DelegatingStatement.execute(DelegatingStatement.java:264)
at org.apache.commons.dbcp.DelegatingStatement.execute(DelegatingStatement.java:264)
at org.sonar.server.platform.db.migration.step.DdlChange$Context.execute(DdlChange.java:82)
... 14 common frames omitted
2018.09.16 22:34:26 INFO  web[][o.s.p.StopWatcher] Stopping process

We use the Azure AAD plugin to manage auth via Azure.

I’d appreciate any help to figure out what went wrong. In the meantime we are restoring the previous database and rolling back to SonarQube 7.1

Let me know if there is any more information you might need.

Kind regards.


(Colin Mueller) #2

Remi,

Checkout this post where the issue has been discussed at length.

Colin