Bug #35307 JDBC executeUpdate hangs/no response
Submitted: 15 Mar 2008 5:29 Modified: 7 Apr 2008 5:12
Reporter: Eduardo Juan Email Updates:
Status: Closed Impact on me:
None 
Category:Connector / J Severity:S2 (Serious)
Version:jdbc driver 5.1.6 OS:Linux (ubuntu gutsy 7.10)
Assigned to: CPU Architecture:Any
Tags: executeUpdate jdbc java hangs timeout response insert

[15 Mar 2008 5:29] Eduardo Juan
Description:
I really don't know how to categorize this behaviour, but it made me loose a lot of hours debugging my java application, and since no 'xyz'Exception was raised and connection was still up (looking at netstat), I thought this may be a bug or, at least, something is not working as expected...

This strange behaviour is all about 'Statement.executeUpdate' hanging or not returning (or raising any exception) in a long time in a INSERT query (i didn't try on a REPLACE or UPDATE query).

Please look at 'How to repeat' to understand better...

My JDBC driver is version 5.1.6. Also tested on JDBC driver version 5.0.8 and same behaviour as the lastest version.

My server version is: 5.0.45-Debian_1ubuntu3.1-log
OS: Ubuntu Gutsy 7.10
IDE: Eclipse  3.3.1.1 Build id: M20071023-1652

How to repeat:
Initial setup:
CREATE TABLE `test` (
  `id` int(11) unsigned NOT NULL auto_increment,
  `field` varchar(20) NOT NULL,
  PRIMARY KEY  (`id`)
) ENGINE=MyISAM DEFAULT CHARSET=latin1;

An "insert into test (field) values ('works')" query just works fine.

But if I add a new DATETIME field not null and execute same query above just hangs on a executeUpdate ;_(

After this setup, executeUpdate() has no response:
CREATE TABLE `test` (
  `id` int(11) unsigned NOT NULL auto_increment,
  `field` varchar(20) NOT NULL,
  `date` datetime NOT NULL,
  PRIMARY KEY  (`id`)
) ENGINE=MyISAM DEFAULT CHARSET=latin1;

Thanks for the attention!
[15 Mar 2008 5:59] Mark Matthews
I just tried this on my machine (w/ 5.1.6, and 5.0.51 on the mac and also with 5.0.45 on gutsy) and I get the following, expected exception in both cases:

"java.sql.SQLException: Field 'date' doesn't have a default value
	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1055)
	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:956)
	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3491)
	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3423)
	at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1936)
	at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2060)
	at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2536)
	at com.mysql.jdbc.StatementImpl.executeUpdate(StatementImpl.java:1564)
	at com.mysql.jdbc.StatementImpl.executeUpdate(StatementImpl.java:1485)
	at testsuite.regression.StatementRegressionTest.testBug35307(StatementRegressionTest.java:5439)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:585)
	at junit.framework.TestCase.runTest(TestCase.java:154)
	at junit.framework.TestCase.runBare(TestCase.java:127)
	at junit.framework.TestResult$1.protect(TestResult.java:106)
	at junit.framework.TestResult.runProtected(TestResult.java:124)
	at junit.framework.TestResult.run(TestResult.java:109)
	at junit.framework.TestCase.run(TestCase.java:118)
	at org.eclipse.jdt.internal.junit.runner.junit3.JUnit3TestReference.run(JUnit3TestReference.java:130)
	at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:460)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:673)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:386)
	at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:196)"

Is there something else you're putting in your JDBC configuration that's not listed here?
[15 Mar 2008 6:09] Eduardo Juan
Oops...sorry..just forgot to put JDBC parameters:

Here they are:
jdbc:mysql://127.0.0.1:3306/mydb?user=user&password=passwd&autoReconnect=false
[15 Mar 2008 6:17] Eduardo Juan
Also tested with 'autoReconnect=true' and same behaviour...

But with 'socketTimeout=1000' an exception is raised:

Communications link failure due to underlying exception: 

** BEGIN NESTED EXCEPTION ** 

java.net.SocketTimeoutException
MESSAGE: Read timed out

STACKTRACE:

java.net.SocketTimeoutException: Read timed out
	at java.net.SocketInputStream.socketRead0(Native Method)
	at java.net.SocketInputStream.read(SocketInputStream.java:129)
	at com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:113)
	at com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:160)
	at com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:188)
	at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:1994)
	at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2411)
	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:2916)
	at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1631)
	at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:1723)
	at com.mysql.jdbc.Connection.execSQL(Connection.java:3277)
	at com.mysql.jdbc.Statement.executeUpdate(Statement.java:1402)
	at com.mysql.jdbc.Statement.executeUpdate(Statement.java:1317)
	at TradeHubBench.ThreadStatsHandler.db_updateBenchnodeData(ThreadStatsHandler.java:449)
	at TradeHubBench.ThreadStatsHandler.run(ThreadStatsHandler.java:207)
	at java.lang.Thread.run(Thread.java:619)

** END NESTED EXCEPTION **

Last packet sent to the server was 1002 ms ago.
[15 Mar 2008 6:26] Eduardo Juan
Going more deeply, my Main thread (static main()) makes only one call for JDBC initialization:

Class.forName("com.mysql.jdbc.Driver").newInstance();
DriverManager.setLoginTimeout(5);

and then in another thread, I just call the usual: 
Connection conn = DriverManager.getConnection(url,user,passwd);
Statement stmt = conn.createStatement();

nothing more simple ;)
[15 Mar 2008 6:37] Eduardo Juan
Sorry, since it's too late here (about 3:33 AM) I almost forgot to put JVM info:
'sun-jdk1.6.0_04' running with arguments: '-Xms256m -Xmx512m'
[15 Mar 2008 20:23] Mark Matthews
Given that you're running JDK 6, update 4, is it possible for you to test using JDK 6 update *5*? We've seen some bugs between recent versions of glibc and JDK 6 before update 5 that manifest themselves as hangs when reading from sockets.
[16 Mar 2008 0:33] Eduardo Juan
I've just finished doing some more tests...All works, even on multithreaded way: on Main thread it initializes jdbc driver and then on the other thread, a connection and statement is created...Everything works just fine.

Some maybe could be due to my app behaviour, since before that buggy statement, a lot of select's and updates are done in the same table as well.

Will be trying with JDK6 update 5, and i promise posting some results in a hour or two.

Thanks!
[16 Mar 2008 1:26] Eduardo Juan
Sorry..bad news :(

Still don't work with jdk6 update 5
[31 Mar 2008 15:00] Mark Matthews
Eduardo, 

We're still not able to reproduce this on our end. Are you sure you're running 5.1.6, and not picking up some older version of the driver from somewhere in your classpath? Can you get us the output of Connection.getMetaData().getDriverVersion() when running your application?
[5 Apr 2008 18:26] Eduardo Juan
Sorry for being late...
Here is the output for 'Connection.getMetaData().getDriverVersion()':
mysql-connector-java-5.1.6 ( Revision: ${svn.Revision} )

I tried to reproduce again this bug on my code, but was unable to do it. Since I modified a lot my Connection handling routines, I cannot see it any more :(

A exception is thrown and the message: Field 'date' doesn't have a default value
makes sense now.

As a work around to that problem, was closing Statement object and creating a new one to use in a different query, since my connection handling routines used to assign different sql queries to a same open Statement object. But now, even if I use the same open Statement object, I can't reproduce this bug any more.

Whenever I encounter this bug again, I will post a more detailed example.

Sorry for all annoyances and thanks for the support!

Best regards,
Eduardo Juan
[7 Apr 2008 5:12] Tonci Grgin
Eduardo, important thing is that your application works now!

Java is not keen on multithreading and it can cause non-obvious behavior / hard to trace errors so be careful.

Thanks for your interest in MySQL.
[29 Jun 2009 23:39] Elmer Garduno
I have the same problem. It can be reproduced if you attempt to do an INSERT using fields like in: 

INSERT INTO test (field) VALUES ('works'),

and the table has another field NOT NULL that isn't declared in the INSERT clause, the insert will hang without throwing any exception.

I fix it changing the field to NULL, or INSERTing a value in that field.
[30 Jun 2009 1:46] Elmer Garduno
Some information that may be useful:

* It fails in version 5.1.6 and also in version 5.1.7 but not in 3.1.12.
* INSERT is executed using:
    PreparedStatement stmt = conn.prepareStatement(query, 
                                           Statement.RETURN_GENERATED_KEYS);
    stmt.executeUpdate();
* Table has an auto_increment field: `ID` int(11) NOT NULL auto_increment
[8 Jul 2009 6:15] Tonci Grgin
Elmer, good place to start would be attaching small but complete Java test case. Please refer to test cases attached to any BugsDB report I verified.
[14 Aug 2009 17:24] Elmer Garduno
Hi, I have created a test case, and tried to reduce it to it's minimal form:

The bug appears when you connect the client (jdbc driver 5.1.6 or jdbc driver 5.1.7) to a MySQL 5.0.41 server running in Solaris 10. If you run the same test case connecting to a MySQL 5.0.67 running in OS X it wont appear. (It will run if you connect using 3.1.12)

The error happens in both MyISAM and InnoDB tables, it may not happen the first time you run it, but if you run it repeatedly it would eventually happen.

Here is the stack trace of the thread dump when the clients hangs:
  
java.lang.Thread.State: RUNNABLE
 at java.net.SocketInputStream.socketRead0(Native Method)
 at java.net.SocketInputStream.read(SocketInputStream.java:129)
 at com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:113)
 at com.mysql.jdbc.util.ReadAheadInputStream. 
     readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:160)
 at com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:188)
        - locked <0xf4079978> (a com.mysql.jdbc.util.ReadAheadInputStream)
 at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:2428)
 at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2882)
 at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2871)
 at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3414)
 at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1936)
 at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2060)
 at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2536)
        - locked <0xf3fcb718> (a java.lang.Object)
 at com.mysql.jdbc.StatementImpl.executeUpdate(StatementImpl.java:1564)
        - locked <0xf3fcb718> (a java.lang.Object)
 at com.mysql.jdbc.StatementImpl.executeUpdate(StatementImpl.java:1485)
 at Test.executeUpdate(Test.java:22)
 at Test.main(Test.java:10)

Here is the code required to recreate it:

CREATE TABLE `test` (
  `field1` varchar(10) NOT NULL,
  `field2` varchar(10) NOT NULL
) ENGINE=MyISAM DEFAULT CHARSET=utf8

import java.sql.Statement;
import java.sql.DriverManager;
import java.sql.Connection;
import java.sql.SQLException;

public final class Test {
   
    public static void main(String[] args) throws Exception {
        Class.forName("com.mysql.jdbc.Driver").newInstance();
        executeUpdate("INSERT INTO test (field1) VALUES ('works')");
    } 

    public static void executeUpdate(String query)  throws SQLException {
        String url = "jdbc:mysql://localhost/test";
        String user = "root";
        String passwd = "";
        Connection conn = null;
        Statement stmt = null;
        try {
            conn = DriverManager.getConnection(url, user, passwd);
            stmt = conn.createStatement();
            stmt.executeUpdate(query);      
            stmt.close();
            stmt = null;
            conn.close();
            conn = null;
        } finally {
            if (stmt != null) {
                try { stmt.close(); } catch (SQLException e) { ; }
                stmt = null;
            }
            if (conn != null) {
                try { conn.close(); } catch (SQLException e) { ; }
                conn = null;
            }
        }
    }
}
[14 Aug 2009 17:31] Elmer Garduno
As Eduardo already noticed the expected behavior should be:

Exception in thread "main" java.sql.SQLException: Field 'field2' doesn't have a default value
	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1055)
	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:956)
	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3491)
	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3423)
	at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1936)
	at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2060)
	at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2536)
	at com.mysql.jdbc.StatementImpl.executeUpdate(StatementImpl.java:1564)
	at com.mysql.jdbc.StatementImpl.executeUpdate(StatementImpl.java:1485)
	at Test.executeUpdate(Test.java:22)
	at Test.main(Test.java:10)
[17 Aug 2009 6:45] Tonci Grgin
Thanks guys, let me check on this today.
[17 Aug 2009 8:00] Tonci Grgin
-Xmx512M -XX:+UseParallelGC -Dcom.mysql.jdbc.java6.javac=C:\jvms\jdk1.6.0\bin\javac.exe -Dcom.mysql.jdbc.java6.rtjar=C:\jvms\jdk1.6.0\jre\lib\rt.jar -Dcom.mysql.jdbc.testsuite.url.default=jdbc:mysql://xx:xx/test?user=xx&password=xx&autoReconnect=false&connectTimeout=5000&socketTimeout=30000&useUnicode=true&characterSetResults=utf8&useInformationSchema=true&useServerPrepStmts=true&cacheResultSetMetadata=true
...
	try {
		createTable("bug35307", "(`field1` varchar(10) NOT NULL, `field2` varchar(10) NOT NULL)ENGINE=MyISAM DEFAULT CHARSET=utf8");
		this.stmt.executeUpdate("INSERT INTO bug35307 (field1) VALUES ('works')");
	} finally {
		closeMemberJDBCResources();
	}
...
produces correct result:
.Loading JDBC driver 'com.mysql.jdbc.Driver'
Done.
Connected to 5.1.31-log
Done.

java.vm.version         : 1.5.0_17-b04
java.vm.vendor          : Sun Microsystems Inc.
java.runtime.version    : 1.5.0_17-b04
os.name                 : Windows Server 2008
os.version              : null
sun.management.compiler : HotSpot Client Compiler
E
Time: 0,329
There was 1 error:
1) testBug35307(testsuite.simple.TestBug35307)java.sql.SQLException: Field 'field2' doesn't have a default value.
[12 Jan 2010 20:20] Olivier Ligny
Here is the solution to the "Field doesn't have a default value" problem :
use parameter jdbcCompliantTruncation=false in the JDBC connection string.