Bug #3409 Connector/J 3.0.11
Submitted: 7 Apr 2004 4:17 Modified: 28 Mar 2014 10:28
Reporter: Ro Gilhespy Email Updates:
Status: Can't repeat Impact on me:
None 
Category:Connector / J Severity:S1 (Critical)
Version:3.0.11 OS:Any (Enterprise Linux.)
Assigned to: Mark Matthews CPU Architecture:Any

[7 Apr 2004 4:17] Ro Gilhespy
Description:
I am currently experiencing a lock up issue which I believe may be related to hyperthreading CPU's and the Connector/J driver.

Setup is as follows:-

Linux Enterprise running 2 hyperthreaded CPU's.

Tomcat 5.0.16 using DBCP 1.1 with Connector/J 3.0.11 and MySQL 4.0.18-standard-log

Intermittently, the JVM will hang inside a call to execute() from either a java statement or prepared statement class. This ONLY happens when the execute call is a SELECT that returns a result set of over a certain size (its approximately 120 rows, with about 20 small numeric and text fields.. not big at all).

Annoyingly, this situation is intermittent, but I have managed to test that it is not the database per se, because calls using the same SELECT statement via php return all the rows immediately.

I cannot get this problem to occur on a windows box, or another non hyperthreaded linux box running redhat 7.

How to repeat:
Not easily.

Replicating the above setup and generating any call to the database that will return a large result set.

This Test JSP which doesn't even use DB Pooling can also hang:-

<%@ page session="true" import="java.sql.*,java.util.*,javax.sql.*,javax.naming.*" %>
<%
String _driverName = "com.mysql.jdbc.Driver";
try
{
    Class.forName(_driverName).newInstance();
}
catch (Exception e)
{
	e.printStackTrace();
	return;
}

String startrow = request.getParameter("startrow");
if (startrow==null) 
	startrow="0";
String endrow = request.getParameter("endrow");
if (endrow==null) 
	endrow="";
else
	endrow=","+endrow;
String _databaseUrl = "jdbc:mysql://localhost/yourdatabase?autoReconnect=true";
String _username = "yourusername";
String _password = "yourpassword";
Connection _dbConn = DriverManager.getConnection(_databaseUrl, _username, _password);
PreparedStatement _pstmt = _dbConn.prepareStatement("SELECT id FROM yourtablename LIMIT "+startrow+endrow+";");
%>
<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01 Transitional//EN">
<html>
<head>
<title>Test of JDBC Connector</title>
<meta http-equiv="Content-Type" content="text/html; charset=iso-8859-1">
</head>

<body>
<%
try
{
    if (_pstmt.execute())
     {
     ResultSet rs = _pstmt.getResultSet();
	 while (rs.next())
          {
 		  out.println(rs.getInt("id")+" ");
		  }
     }
}
catch (SQLException sqle)
{
}
_dbConn.close();
%>
</body>
</html>

Suggested fix:
help!
[7 Apr 2004 4:21] Ro Gilhespy
jdk version 1.4.2_03 and 1.4.2_04 tried.
Both intermittently hang.
[7 Apr 2004 7:11] Mark Matthews
Can you please post a thread dump of your application when it is in this hung state (send a 'kill - 3' to the JVM, and it will print what all the threads in the VM are doing to STDOUT, which should be logged somewhere in your tomcat install).

My guess is that you will see at least one thread blocking for I/O from the server, which is a known issue with java.io.BufferedInputStream that is solved with the nightly snapshots of 3.0.x from http://downloads.mysql.com/snapshots.php or alternatively by setting the JDBC URL property 'useUnbufferedInput' to true...In 3.0.11 this property was introduced, and the default was 'false', starting with 3.0.12 unbuffered input will be enabled by default.
[7 Apr 2004 11:45] Ro Gilhespy
I'll try and catch it again when its hung and get the thread info.

I'll also use the nightly build 20040407 and hope that resolves it.

However, you mentioned using property useUnbufferedInput=true.

According to the documentation for 3.0.11, this property is not required but defaults to true, so doesn't that mean is already set ? Or are the docs wrong ?
[7 Apr 2004 12:05] Ro Gilhespy
hmmm... swapped out 3.0.11 with nightly build 20040407 and I immediately get an error attempting to create the DB pool:-

SQL Exception - Couldn't connect to database. org.apache.commons.dbcp.SQLNestedE
xception: Cannot create PoolableConnectionFactory, cause: General error,  messag
e from server: "Unknown system variable 'character_set_results'"

This is running on my windows development Pc (windows xp), all other tomcat and mysql versions the same as originally posted.
[7 Apr 2004 12:08] Ro Gilhespy
My apologies.. wrong nightly build!
[7 Apr 2004 12:10] Ro Gilhespy
Scratch that.. it was the right nightly build.. but its looking for a variable I believe is in MySQL 4.1, but I am running 4.0.18
[8 Apr 2004 1:49] Ro Gilhespy
It would appear that the thread is hanging in java.net.SocketInputStream.socketRead0.. This is WITH unbufffered explicitly set to TRUE in the JDBC URL:- 

jdbc:mysql://localhost/rogil_mydatabase?autoReconnect=true&amp;autoReconnectForPools=true&amp;useUnbufferedInput=true

Full thread dump Java HotSpot(TM) Client VM (1.4.2_04-b05 mixed mode):

"http8443-Monitor" prio=1 tid=0x0821f198 nid=0x651d in Object.wait() [a819b000..a819b87c]
	at java.lang.Object.wait(Native Method)
	- waiting on <0xab809b58> (a org.apache.tomcat.util.threads.ThreadPool$MonitorRunnable)
	at org.apache.tomcat.util.threads.ThreadPool$MonitorRunnable.run(ThreadPool.java:560)
	- locked <0xab809b58> (a org.apache.tomcat.util.threads.ThreadPool$MonitorRunnable)
	at java.lang.Thread.run(Thread.java:534)

"http8443-Processor25" daemon prio=1 tid=0x0821e498 nid=0x651d runnable [a821b000..a821c87c]
	at java.net.SocketInputStream.socketRead0(Native Method)
	at java.net.SocketInputStream.read(SocketInputStream.java:129)
	at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:1316)
	at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:1463)
	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:1854)
	at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1109)
	at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:1203)
	at com.mysql.jdbc.Connection.execSQL(Connection.java:2090)
	- locked <0xaaddf0b8> (a java.lang.Object)
	at com.mysql.jdbc.PreparedStatement.execute(PreparedStatement.java:1308)
	- locked <0xaaddf0b8> (a java.lang.Object)
	at org.apache.commons.dbcp.DelegatingPreparedStatement.execute(DelegatingPreparedStatement.java:256)
	at net.k00l.DBHandler.lookup(DBHandler.java:230)
	- locked <0xaadde140> (a net.k00l.DBHandler)
	at net.k00l.shop.ProductAndCategory.GetSearchRows(ProductAndCategory.java:1267)
	at net.k00l.shop.ProductAndCategory.SearchByAdvancedSearch(ProductAndCategory.java:1251)
	- locked <0xab9162a8> (a net.k00l.shop.ProductAndCategory)
	at net.k00l.shop.ProductAndCategory.SearchBy(ProductAndCategory.java:1338)
	- locked <0xab9162a8> (a net.k00l.shop.ProductAndCategory)
	at net.k00l.shop.ShopServ.doGet(ShopServ.java:228)
	at net.k00l.shop.ShopServ.doPost(ShopServ.java:45)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:763)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:856)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:284)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:204)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:256)
	at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:151)
	at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:564)
	at org.apache.catalina.core.StandardContextValve.invokeInternal(StandardContextValve.java:245)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:199)
	at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:151)
	at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:564)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:195)
	at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:151)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:164)
	at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:149)
	at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:564)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:156)
	at org.apache.catalina.core.StandardValveContext.invokeNext(StandardValveContext.java:151)
	at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:564)
	at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:972)
	at org.apache.coyote.tomcat5.CoyoteAdapter.service(CoyoteAdapter.java:211)
	at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:805)
	at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.processConnection(Http11Protocol.java:696)
	at org.apache.tomcat.util.net.TcpWorkerThread.runIt(PoolTcpEndpoint.java:605)
	at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:677)
	at java.lang.Thread.run(Thread.java:534)

"http8443-Processor24" daemon prio=1 tid=0x0821d798 nid=0x651d runnable [a829d000..a829d87c]
	at java.net.PlainSocketImpl.socketAccept(Native Method)
	at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:353)
	- locked <0xab3f2f18> (a java.net.PlainSocketImpl)
	at java.net.ServerSocket.implAccept(ServerSocket.java:448)
	at com.sun.net.ssl.internal.ssl.SSLServerSocketImpl.accept(DashoA6275)
	at org.apache.tomcat.util.net.jsse.JSSESocketFactory.acceptSocket(JSSESocketFactory.java:149)
	at org.apache.tomcat.util.net.PoolTcpEndpoint.acceptSocket(PoolTcpEndpoint.java:387)
	at org.apache.tomcat.util.net.TcpWorkerThread.runIt(PoolTcpEndpoint.java:569)
	at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:677)
	at java.lang.Thread.run(Thread.java:534)

"http8443-Processor23" daemon prio=1 tid=0x0821ca98 nid=0x651d in Object.wait() [a831e000..a831e87c]
	at java.lang.Object.wait(Native Method)
	- waiting on <0xab809cf8> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
	at java.lang.Object.wait(Object.java:429)
	at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:653)
	- locked <0xab809cf8> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
	at java.lang.Thread.run(Thread.java:534)
[8 Apr 2004 2:27] Ro Gilhespy
Whilst the app was in hung state, I tried a few other things:-

Setting a socket timeout Using SocketTimeout=5000 cured the hang, but I get no results back.

useNewIO=true made no difference at all.

Alpha driver 3.1.1 also suffered the same hang as 3.0.11
[8 Apr 2004 6:09] Mark Matthews
Please try last nights nightly build, as it fixes the 'character_set_results' issue, and I would like to see if it fixes this issue as well.
[8 Apr 2004 8:39] Ro Gilhespy
Nightly build 20040408 does run (the character sets issues is resolved) but the application still hangs in exactly the same way.
[8 Apr 2004 10:16] Ro Gilhespy
Has this issue been reported before ?
I'm suprised that its not surfaced until now.

Its currently causing a major problem on a production site and I need to resolve it as quickly as possible.

It only appears to happen on a one box that is dual processored, is that just a coincidence ?

Thanks for you help.

Ro.
[8 Apr 2004 10:29] Mark Matthews
Nothing exactly similar to this has been reported, only hangs due to buffered input stream's broken-ness, or protocol-mismatch/bugs (only 2-3 reports of that out of 10's of thousands of known users).

Which version of Enterprise Linux is this? 3.0AS? We have seeen issues with NPTL under load with MySQL (are you using are binary), and there might be issues with NPTL and the JVM under high load as well.
[8 Apr 2004 11:10] Ro Gilhespy
Linux version is: Enterprise Linux ES Version 3.
Kernel: 2.4.21-9.0.1.Elsmp

Server is NOT under high load.. infact the opposite.
[8 Apr 2004 11:42] Mark Matthews
Are you using _our_ binaries, something you compiled yourself, or something from RedHat? If they're not _our_ binaries, please test using _our_ binaries (we don't recommend running self-compiled or other vendors' builds of MySQL unless absolutely necessary).
[8 Apr 2004 11:52] Ro Gilhespy
I believe the binaries are yours. The host that has setup this box uses cpanel/whm and mysql comes as part of the cpanel install.
[9 Apr 2004 7:34] Mark Matthews
What you have reported doesn't definitively tell us whether or not they are official MySQL AB binaries or not. 

What does the output of "show variables like 'version_comment'" when run in the MySQL client say?
[9 Apr 2004 10:09] Ro Gilhespy
mysql --version reports:-

mysql  Ver 12.22 Distrib 4.0.18, for pc-linux (i686)
[20 Oct 2004 10:47] Alan Williamson
Having just read this bug, I can add my vote to it.  We are running MySQL binaries, and we find that every so often, it locks in this method.  Nothing gets it back from here; and we have to restart the process

at java.net.SocketInputStream.socketRead0(Native Method) 
at java.net.SocketInputStream.read(Unknown Source) 
at java.io.BufferedInputStream.fill(Unknown Source) 
at java.io.BufferedInputStream.read1(Unknown Source) 
at java.io.BufferedInputStream.read(Unknown Source) 
- locked <0x46a20d70> (a java.io.BufferedInputStream) 
at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:1316) 
at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:1463) 
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:1854) 
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1109) 
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:1203) 
at com.mysql.jdbc.Connection.execSQL(Connection.java:2090) 
- locked <0x46a20790> (a java.lang.Object) 
at com.mysql.jdbc.PreparedStatement.execute(PreparedStatement.java:1308) 

Versions:
mysql  Ver 12.21 Distrib 4.0.15, for pc-linux (i686)
MySQL Connector/J 3.0.11-stable 
Java(TM) 2 Runtime Environment, Standard Edition (build 1.4.2_02-b03)

The only other thing i can note is that the queries for us are very simple; 3 column table inserting ONE row.  One of the columns is a blob; potentially going to very high KB (~200KB).
[20 Oct 2004 13:13] Mark Matthews
This should be fixed in the latest release, it's a bug with BufferedInputStream. (Notice the latest release is 3.0.14, so you're at least 3 releases behind).

When filing bugs, please make sure you're using the latest version of the driver.
[21 Oct 2004 12:36] Alan Williamson
We have just upgraded to the newest driver and suddenly our application has stopped working.  This is why one should never blindly upgrade or always use the latest releases!

In the 3.0.15 release, A mysql column of type TINYINT(1) is now treated as a BIT field in the driver!  Which is incorrect.  A TINYINT(1) holds 0-9 not just 0-1.

So we'll have to roll back to the previous version until a fix is made.
[18 Jul 2006 15:31] Glenn Kirsten
I got the same problem in the newest drivers

jdbc driver is 3.1.13

database is 4.1.20
[28 Mar 2014 10:28] Alexander Soklakov
I close this report as "Can't repeat" because there is no feedback for a long time and codebase is too old. Please, feel free to reopen it if the problem still exists in current driver.