DB Migration communications link failure 5.6.6 to 6.7.5

database
mysql

(Matt Drozdz) #1

I was in the process of upgrading Sonar from 5.6.6 to 6.7.5 and ran into this issue in our Staging environment with the following error in the web.log. I did not run into this error in dev or test. Is there any way to prevent this from happening? I just kicked off the upgrade again to see what happens this time.

2018.09.04 20:53:25 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 #1207 'Drop unused columns on PROJECT_MEASURES' 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.util.Iterator.forEachRemaining(Iterator.java:116)
        at java.util.Spliterators$IteratorSpliterator.forEachRemaining(Spliterators.java:1801)
        at java.util.stream.ReferencePipeline$Head.forEachOrdered(ReferencePipeline.java:590)
        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:50)
        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)
        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.v60.DropUnusedMeasuresColumns.execute(DropUnusedMeasuresColumns.java:48)
        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)
        ... 11 common frames omitted
        Suppressed: java.sql.SQLException: Already closed.
                at org.apache.commons.dbcp.PoolableConnection.close(PoolableConnection.java:114)
                at org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.close(PoolingDataSource.java:191)
                at org.sonar.server.platform.db.migration.step.DdlChange.execute(DdlChange.java:46)
                ... 12 common frames omitted
Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure

The last packet successfully received from the server was 4,382,690 milliseconds ago.  The last packet sent successfully to the server was 4,382,688 milliseconds ago.
        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.SQLError.createCommunicationsException(SQLError.java:989)
        at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3559)
        at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3459)
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3900)
        at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2527)
        at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2680)
        at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2486)
        at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2444)
        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)
        ... 16 common frames omitted
Caused by: java.io.EOFException: Can not read response from server. Expected to read 4 bytes, read 0 bytes before connection was unexpectedly lost.
        at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:3011)
        at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3469)
        ... 27 common frames omitted

(G Ann Campbell) #2

Hi,

From your logs

It looks like your DB stopped responding (4382688 milliseconds ~= 73 minutes).

I’d investigate this at your DB or in the network in between.

Ann


(Matt Drozdz) #3

Thanks. I noticed that mysql is not recommended according to https://docs.sonarqube.org/display/SONAR/Installing+the+Server. Has this always been the case or is this something new? I’m trying to still debug what the exact issue is. Just to also point out the database is running in AWS as MySQL 5.6.34 and this is my jdbc url jdbc:mysql://xxxxxxxx.us-east-1.rds.amazonaws.com:3306/sonar?useUnicode=true&characterEncoding=utf8&useSSL=true&verifyServerCertificate=false&rewriteBatchedStatements=true&useConfigs=maxPerformance. Do you think adding
autoReconnect=true would be helpful to add to the connection string?


(G Ann Campbell) #4

Hi,

Discouraging MySQL is relatively recent. FYI, we plan to do more than discourage it (SONAR-10777).

 
Ann


(Matt Drozdz) #5

Thanks for letting me know. We will plan to switch off soon then. I just completed our Staging upgrade and the DB migration took 27 hours to complete. Is there any recommendations on how to increase that or should we just plan for a 27 hour outage?


(Kay) #6

We are upgrading from 5.6.3 to 6.7.5 and have the exact same issue with same error. I am using Mysql-5.6.29. Is there a solution for this.


(Matt Drozdz) #7

Yes, my issue was that I was running out of DB Space. If you monitor it during the upgrade you will see that it uses a lot of storage so I added about 100ish GB and I got past the error.


(Kay) #8

I will take a look. Thank You


(Kay) #9

Issue with space was resolved however, I end up with below error. I have increased the limits and set the parameters as per link - https://docs.sonarqube.org/display/SONAR/Requirements
but no matter what I do I always end up with the same error. Any suggestions will be helpful

2018.10.21 10:59:31 INFO web[][DbMigrations] #1207 ‘Drop unused columns on PROJECT_MEASURES’…

2018.10.21 11:28:03 WARN web[][o.s.p.ProcessEntryPoint] Fail to start web

java.lang.IllegalArgumentException: Unable to create shared memory :

at org.sonar.process.sharedmemoryfile.AllProcessesCommands.<init>(AllProcessesCommands.java:100)

at org.sonar.process.sharedmemoryfile.DefaultProcessCommands.<init>(DefaultProcessCommands.java:34)

at org.sonar.process.sharedmemoryfile.DefaultProcessCommands.secondary(DefaultProcessCommands.java:52)

at org.sonar.server.app.WebServer.isOperational(WebServer.java:68)

at org.sonar.server.app.WebServer.getStatus(WebServer.java:60)

at org.sonar.process.ProcessEntryPoint.waitForOperational(ProcessEntryPoint.java:145)

at org.sonar.process.ProcessEntryPoint.launch(ProcessEntryPoint.java:120)

at org.sonar.process.ProcessEntryPoint.launch(ProcessEntryPoint.java:100)

at org.sonar.server.app.WebServer.main(WebServer.java:91)

Caused by: java.io.FileNotFoundException: /opt/sonarqube-6.7.5/temp/sharedmemory (Too many open files in system)

at java.io.RandomAccessFile.open0(Native Method)

at java.io.RandomAccessFile.open(RandomAccessFile.java:316)

at java.io.RandomAccessFile.<init>(RandomAccessFile.java:243)

at org.sonar.process.sharedmemoryfile.AllProcessesCommands.<init>(AllProcessesCommands.java:97)

… 8 common frames omitted


(G Ann Campbell) #10

Hi Kay,

New error, new thread please.

 
:slight_smile:
Ann