2012-09-09 50 views
2

我使用飛行用1.5和mysql Ver 14.14 Distrib 5.1.52, for unknown-linux-gnu (x86_64) using readline 5.1連接超時的遷徙路線

我寫了下面的遷移:

alter table table1 add column col_11 blob; 
alter table table1 add column col_12 varchar(255) DEFAULT NULL; 

alter table table2 add column col_21 blob; 
alter table table2 add column col_22 varchar(255) DEFAULT NULL; 

哪裏table1小,table2有283018行。

遷移成功(列已添加到table1table2),但版本更新失敗(我得到com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after connection closed.)。

my.cnf文件保存下一行wait_timeout=30,我還以爲發生了什麼事,加入這兩列table2花了超過wait_timout - 這「失敗」遷移 - 現在我有這種情況:遷移已成功,但該版本未更新。但後來我跑這條SQL查詢:

show variables like "%timeout%"; 

,並得到這樣的:

+----------------------------+-------+ 
| Variable_name    | Value | 
+----------------------------+-------+ 
| connect_timeout   | 10 | 
| delayed_insert_timeout  | 300 | 
| innodb_lock_wait_timeout | 50 | 
| innodb_rollback_on_timeout | OFF | 
| interactive_timeout  | 28800 | 
| net_read_timeout   | 30 | 
| net_write_timeout   | 60 | 
| slave_net_timeout   | 3600 | 
| table_lock_wait_timeout | 50 | 
| wait_timeout    | 28800 | 
+----------------------------+-------+ 

這表明wait_timeout爲8小時左右......

所以我的問題是爲什麼此連接超時發生?

主要是 - 我該如何解決它?

編輯: 應用程序和數據庫都在同一臺機器上。

以下是完整的堆棧跟蹤:

Current schema version: 12.9.3 
Migrating to version 12.9.3.1 

Error while extracting database product name - falling back to empty error codes 
org.springframework.jdbc.support.MetaDataAccessException: Error while extracting DatabaseMetaData; nested exception is com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after connection closed. 
    at org.springframework.jdbc.support.JdbcUtils.extractDatabaseMetaData(JdbcUtils.java:296) 
    at org.springframework.jdbc.support.JdbcUtils.extractDatabaseMetaData(JdbcUtils.java:320) 
    at org.springframework.jdbc.support.SQLErrorCodesFactory.getErrorCodes(SQLErrorCodesFactory.java:216) 
    at org.springframework.jdbc.support.SQLErrorCodeSQLExceptionTranslator.setDataSource(SQLErrorCodeSQLExceptionTranslator.java:140) 
    at org.springframework.jdbc.support.SQLErrorCodeSQLExceptionTranslator.<init>(SQLErrorCodeSQLExceptionTranslator.java:103) 
    at org.springframework.jdbc.support.JdbcAccessor.getExceptionTranslator(JdbcAccessor.java:99) 
    at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:407) 
    at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:522) 
    at com.googlecode.flyway.core.metadatatable.MetaDataTable.insert(MetaDataTable.java:149) 
    at com.googlecode.flyway.core.migration.DbMigrator.applyMigration(DbMigrator.java:248) 
    at com.googlecode.flyway.core.migration.DbMigrator$1.doInTransaction(DbMigrator.java:148) 
    at com.googlecode.flyway.core.migration.DbMigrator$1.doInTransaction(DbMigrator.java:114) 
    at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:128) 
    at com.googlecode.flyway.core.migration.DbMigrator.migrate(DbMigrator.java:113) 
    at com.googlecode.flyway.core.Flyway.migrate(Flyway.java:619) 
    at com.googlecode.flyway.commandline.Main.main(Main.java:79) 
Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after connection closed. 
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) 
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57) 
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) 
    at java.lang.reflect.Constructor.newInstance(Constructor.java:532) 
    at com.mysql.jdbc.Util.handleNewInstance(Util.java:411) 
    at com.mysql.jdbc.Util.getInstance(Util.java:386) 
    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1013) 
    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:987) 
    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:982) 
    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:927) 
    at com.mysql.jdbc.ConnectionImpl.throwConnectionClosedException(ConnectionImpl.java:1205) 
    at com.mysql.jdbc.ConnectionImpl.checkClosed(ConnectionImpl.java:1197) 
    at com.mysql.jdbc.ConnectionImpl.getMetaData(ConnectionImpl.java:3061) 
    at com.mysql.jdbc.ConnectionImpl.getMetaData(ConnectionImpl.java:3056) 
    at org.springfra 
mework.jdbc.support.JdbcUtils.extractDatabaseMetaData(JdbcUtils.java:285) 
    ... 15 more 
Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure 
The last packet successfully received from the server was 654,699 milliseconds ago. The last packet sent successfully to the server was 17 milliseconds ago. 
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) 
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57) 
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) 
    at java.lang.reflect.Constructor.newInstance(Constructor.java:532) 
    at com.mysql.jdbc.Util.handleNewInstance(Util.java:411) 
    at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1116) 
    at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3102) 
    at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2991) 
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3532) 
    at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2002) 
    at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2163) 
    at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2618) 
    at com.mysql.jdbc.StatementImpl.executeUpdate(StatementImpl.java:1749) 
    at com.mysql.jdbc.StatementImpl.executeUpdate(StatementImpl.java:1666) 
    at org.springframework.jdbc.core.JdbcTemplate$1UpdateStatementCallback.doInStatement(JdbcTemplate.java:512) 
    at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:396) 
    ... 9 more 
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:2552) 
    at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3002) 
    ... 18 more 
Application exception overridden by rollback exception 
org.springframework.dao.RecoverableDataAccessException: StatementCallback; SQL [UPDATE schema_version SET current_version=0]; Communications link failure 
The last packet successfully received from the server was 654,699 milliseconds ago. The last packet sent successfully to the server was 17 milliseconds ago.; nested exception is com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure 
The last packet successfully received from the server was 654,699 milliseconds ago. The last packet sent successfully to the server was 17 milliseconds ago. 
    at org.springframework.jdbc.support.SQLExceptionSubclassTranslator.doTranslate(SQLExceptionSubclassTranslator.java:97) 
    at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:72) 
    at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:80) 
    at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:407) 
    at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:522) 
    at com.googlecode.flyway.core.metadatatable.MetaDataTable.insert(MetaDataTable.java:149) 
    at com.googlecode.flyway.core.migration.DbMigrator.applyMigration(DbMigrator.java:248) 
    at com.googlecode.flyway.core.migration.DbMigrator$1.doInTransaction(DbMigrator.java:148) 
    at com.googlecode.flyway.core.migration.DbMigrator$1.doInTransaction(DbMigrator.java:114) 
    at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:128) 
    at com.googlecode.flyway.core.migration.DbMigrator.migrate(DbMigrator.java:113) 
    at com.googlecode.flyway.core.Flyway.migrate(Flyway.java:619) 
    at com.googlecode.flyway.commandline.Main.main(Main.java:79) 
Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: Communications link failure 
The last packet successfully received from the server was 654,699 milliseconds ago. The last packet sent successfully to the server was 17 milliseconds ago. 
    at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) 
    at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57) 
    at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) 
    at java.lang.reflect.Constructor.newInstance(Constructor.java:532) 
    at com.mysql.jdbc.Util.handleNewInstance(Util.java:411) 
    at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1116) 
    at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3102) 
    at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2991) 
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3532) 
    at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2002) 
    at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2163) 
    at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2618) 
    at com.mysql.jdbc.StatementImpl.executeUpdate(StatementImpl.java:1749) 
    at com.mysql.jdbc.StatementImpl.executeUpdate(StatementImpl.java:1666) 
    at org.springframework.jdbc.core.JdbcTemplate$1UpdateStatementCallback.doInStatement(JdbcTemplate.java:512) 
    at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:396) 
    ... 9 more 
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:2552) 
    at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3002) 
    ... 18 more 
FlywayException: Migration failed ! 
Occured in com.googlecode.flyway.core.migration.DbMigrator in method migrate, line number 164 
Caused by java.io.EOFException: Can not read response from server. Expected to read 4 bytes, read 0 bytes before connection was unexpectedly lost. 
Occured in com.mysql.jdbc.MysqlIO in method readFully, line number 2552 

回答

1

分析了一下:

由於遷飛命令行工具創建兩個新的連接,它啓動時,連接的陳舊可以排除。

Flyway將首先打開元數據表的連接並將其鎖定。

然後它將打開第二個連接並執行遷移。我假設這一步需要很長時間(從原木中減去+ - 11分鐘)。

遷移完成後,第二個連接上的事務將提交,並且新行將通過第一個連接添加到元數據表中。

這是炸彈的地方......但是有了通信而不是連接超時或鎖定超時異常。

難道應用程序和數據庫之間的某些網絡設備(路由器/交換機/代理)會丟失不活動的連接嗎?

+0

感謝您的回覆。 首先,應用程序和數據庫在同一臺計算機上(本地主機) - 所以我不認爲你提出的是什麼問題(但我不知道)。 這裏是另一件事 - 當我使用c3p0是應用程序 - 拋出同樣的異常。 – Noam

2

我們剛剛遇到此問題並設法找到了適用於我們的解決方案。似乎Flyway至少使用兩個連接:一個鎖定schema_version表,另一個連接實際運行修改。當更改花費足夠長時間導致鎖定schema_version表的超時連接時,會發生此問題。解決這個問題的最簡單方法是將MySQL wait_timeout升級爲相對較大的東西。在我們的例子中,我們將其設置爲480分鐘(或28800秒):

set global wait_timeout=28800; 
+0

是否可以更改僅用於flyway連接的mysql超時值?我還沒有找到辦法自己做。 – Rob

+0

另外,請注意全局wait_timeout和wait_timeout可以設置爲不同的值。我遇到了同樣的問題,當我做了一個SELECT @@ global.wait_timeout,@@ session.wait_timeout;'mine session.wait_timeout是28800,而global.wait_timeout是600 – Marcelo