| Bug #1732 | Intermittently throws "Unexpected End of Input Stream" | ||
|---|---|---|---|
| Submitted: | 1 Nov 2003 9:22 | Modified: | 28 Mar 2014 12:10 |
| Reporter: | tom werges | Email Updates: | |
| Status: | Can't repeat | Impact on me: | |
| Category: | Connector / J | Severity: | S1 (Critical) |
| Version: | Connector/J 3.0.9 | OS: | Linux (Linux (RH9)) |
| Assigned to: | Alexander Soklakov | CPU Architecture: | Any |
[4 Nov 2003 10:18]
Mark Matthews
This thread is in java@lists.mysql.com as well (seems to be from same user). We're waiting for feedback to the following question:
tom@zimage.com said:
>>
>> My guess is that you've hit whatever timeout MySQL has for idle
>> connections (by default it's 8 hours, but there's a chance it might be
>> different on your server). This question is covered in the docs, in the
>> Troubleshooting section (look for topic '4.4. I have a
>> servlet/application that works fine for a day, and then stops working
>> overnight') at:
>>
>> http://www.mysql.com/documentation/connector-j/index.html#id2802490
>>
>> -Mark
>
> Mark,
>
> That may very well be the difficulty. However the documentation you
> referenced says the following:
>
> "you should be catching SQLExceptions in your application and dealing with
> them, rather than propagating them all the way until your application
> exits... MySQL Connector/J will set the SQLState (see
> java.sql.SQLException.getSQLState() in your APIDOCS) to '08S01' when it
> encounters network-connectivity issues during the processing of a query.
> Your application code should then attempt to re-connect to MySQL at this
> point"
>
> ...Note that we're catching all SQLExceptions and replacing connections
> already. So, we were already doing what the documentation recommended to
> avoid this problem. But no SQLException was ever thrown, as the docs
> claimed; and nothing in the error message indicated that this could be the
> problem (it didn't say "connection closed" or anything similar); and of
> course it's impossible to get an SQLState from an IOException.
You can't get an IOException from calling any method in the JDBC API. It's
a checked exception, so what you're seeing is actually an SQLException
that says an IOException ocurred (Connector/J wraps the IOExceptions with
an SQLException, and then sets the SQLState to "08S01"). The stacktrace
you pasted in your earlier e-mail is a _nested_ stack trace from the
SQLException (which the driver does to aid diagnosing these things, and
was added before Java supported 'netsted' exceptions).
>
> In addition, I tinkered with connections a bit and found that I could get
> them to die by purposefully doing erroneous things. For example, the
> following code:
>
> for (int j = 0; j < 30; j++) {
> DBConn conn = ConnPool.getConnection();
> HashSet pstmts = new HashSet();
> for (int i = 0; i < 30; i++) {
> PreparedStatement pstmt =
> conn.prepareStatement("SELECT * FROM projects WHERE id = 2");
> pstmts.add(pstmt);
> ResultSet rs = pstmt.executeQuery();
> while (rs.next()) {
> hash += rs.getString("name").hashCode();
> }
> //forget to close statements
> //pstmt.close();
> }
> //leak connections
> //ConnPool.returnConnection(conn);
> }
>
> ...will cause all connections in the pool to spontaneously close, after
> only a small number of the connections have been "leaked." Perhaps this is
> a bug in the connection pooler I'm using... Do you get the same result?
No, I don't. We load test the driver with many connection pools (JBoss,
DBCP from Jakarta, WebLogic, WebSphere), and don't see this behavior. Is
this a custom connection pool that you have developed?
> Setting "autoReconnect" to "true" does not make the other connections
> re-connect.
The connections have to be in autoCommit(true) mode to reconnect? Does
your pool 'hold' connections in autoCommit(false) for any reason?
>
> I realize that it's the responsibility of the connection pooler to monitor
> connections and replace them when necessary. Still, as a suggested
> improvement, perhaps Connector/J should:
> 1. have autoReconnect=true by default
AutoReconnect has a _lot_ of overhead that is not normally needed, so that
is why it's not set to default. It also is not usually the 'correct' way
to approach things, because only the application itself knows whether a
transaction should really be retried, or abandoned (rather than just
blindly forging ahead).
> 2. throw an SQLException if a connection has died or expired, which says
> "connection died/expired."
The driver already does this (the SQLState of an I/O error with the server
is '08S01'). The driver _can't_ tell whether the connection died due to a
network error, or the server timing it out, because they both look the
same from the client side.
> 3. have it such that any number of leaked connections or unclosed
> statements won't cause any other connections to close or fail.
They don't, usually. My guess is that it is something specific with your
particular setup, configuration, or connection pooler (I haven't had
behavior like this reported before). Statements and PreparedStatements
(other than for Connector/J 3.1 connected to MySQL-4.1 or newer) are all
client-side resources that have _nothing_ to do with the network
connectivity.
[21 Nov 2003 7:25]
Denis Signoretto
Hi Mark,
I Have a similar problem as Tom. As you suggested I modified my Java code to detect, and recover connection errors. The problem is that the exception on a connection is not generated immediatly but after an 8 ours internal time out.
I tryed also to setup "connectTimeout" and "socketTimeout" parameters on connection string but it seems to be ignored.
This is my code and my application log. As you can see the exception log
is produced only after a long 8 hours period, so I can't recover
the connection in a useful time. I also tried with or without autoCommit
and autoReconnect. The only difference is that anabling them after 8 hours
period I get a successful reconnection without exception (but always after 8
8 hours).
Have you got any suggestion?
public Connection getConnection() {
Log.writelnDetails("Opening a new Database Connection.");
Connection conn = null;
try {
conn = DriverManager.getConnection("jdbc:mysql://" +
ConfigFactory.getInstance().getDatabaseHost() + "/" +
ConfigFactory.getInstance().getDatabaseName() + "?user=" +
ConfigFactory.getInstance().getDatabaseUser() + "&password="
+
ConfigFactory.getInstance().getDatabasePasswd() +
// "&autoReconnect=true" +
"&=socketTimeout" +
ConfigFactory.getInstance().getDatabaseTimeout() +
"&=connectTimeout" +
ConfigFactory.getInstance().getDatabaseTimeout() +
""
);
// conn.setAutoCommit(true);
Log.writelnDetails("Connection Opened.");
} catch (SQLException e) {
PrintLog.printOnError("Database Connection Failure on connect()
method.\n" +
"SQLState=" + e.getSQLState() + ", ErrorCode=" +
e.getErrorCode(), e);
final int RETRIES =
ConfigFactory.getInstance().getDatabaseRetries();
Connection retriedConn = null;
for (int i=0; i<RETRIES; i++) {
retriedConn = reconnect();
if (retriedConn != null) {
PrintLog.printOnError("Re-Connection on retries " + (i+1) +
" esthablished.", e);
} else {
PrintLog.printOnError("Re-Connection on retries " + (i+1) +
" still failed.", e);
}
}
// System.exit(1);
}
return conn;
}
[Wed 2003-11-19 18:55:00] Opening a new Database Connection.
[Thu 2003-11-20 02:55:00] Database Connection Failure on connect() method.
SQLState=08S01, ErrorCode=0
[Thu 2003-11-20 02:55:00] Communication link failure: java.io.IOException,
underlying cause: Unexpected end of input stream
** BEGIN NESTED EXCEPTION **
java.io.IOException
MESSAGE: Unexpected end of input stream
STACKTRACE:
java.io.IOException: Unexpected end of input stream
at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:1405)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:1775)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1020)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:1109)
at com.mysql.jdbc.MysqlIO.sqlQuery(MysqlIO.java:1070)
at com.mysql.jdbc.Connection.execSQL(Connection.java:2027)
at com.mysql.jdbc.Connection.execSQL(Connection.java:1996)
at com.mysql.jdbc.Connection.execSQL(Connection.java:1977)
at com.mysql.jdbc.Connection.setAutoCommit(Connection.java:654)
at
com.mysql.jdbc.Connection.initializePropsFromServer(Connection.java:2623)
at com.mysql.jdbc.Connection.createNewIO(Connection.java:1750)
at com.mysql.jdbc.Connection.<init>(Connection.java:562)
at
com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:361)
at java.sql.DriverManager.getConnection(DriverManager.java:512)
at java.sql.DriverManager.getConnection(DriverManager.java:193)
at com.acplab.astanet.archivi.Database.getConnection(Database.java:372)
at
com.acplab.astanet.archivi.SnmpDataDB.insertMultipleSnmpCollectedData(SnmpDataDB
.java:151)
at
com.acplab.astanet.services.pollerd.StoreDataMultipleThread.storeAllThreadsData(
StoreDataMultipleThread.java:105)
at com.acplab.astanet.services.pollerd.Pollerd.run(Pollerd.java:194)
at java.util.TimerThread.mainLoop(Timer.java:432)
at java.util.TimerThread.run(Timer.java:382)
** END NESTED EXCEPTION **
Thanks,
Denis.
[21 Nov 2003 7:51]
Mark Matthews
>This is my code and my application log. As you can see the exception log >is produced only after a long 8 hours period, so I can't recover >the connection in a useful time. I also tried with or without autoCommit >and autoReconnect. The only difference is that anabling them after 8 hours >period I get a successful reconnection without exception (but always after 8 >8 hours). I don't understand this last part of your comment. The MySQL server disconnects 'idle' connections after a certain amount of time, specified by the 'wait_timeout' variable on the server...socket or connect timeouts on the client side have _nothing_ to do with it. Those values are for timing out connections that take to long to establish (connect timeout), or operations that 'hang' while waiting for network I/O (socket timeout). I'm still at a loss why your application can't recover from being disconnected after 8 hours. Once this happens, the JDBC driver will throw a SQLException with SQLState == "08S01". Since you don't post the code to your reConnect() method, it's hard to tell what's going on in your code. Have you walked through your code in a debugger to see how it's actually handling this? I have a feeling your missing catching an exception somewhere (but that's just a guess).
[21 Nov 2003 9:03]
Denis Signoretto
Mark, Thanks al lot about connection and socket timeout explanation. About my previous message, sorry, probably I haven't explained myself very well. Anyway... the problem is that "Connection Opened" log command is never reached and something goes wrong on "conn = DriverManager.getConnection(...)" method. The exception (look at the hour of log) is generated only after 8 hour. Until this happen no Stamentent are executed and the application hangs up. Usually, my application when need to access MySQL open a new connection, execute some statement, and close the connection (I know this is not good for performance). What I can say is that this happen randomly and when happen the socket is in established state but no statements are executed. Denis.
[28 Nov 2003 3:14]
Denis Signoretto
Hi Mark, I modified my code with a simple connection pool, that start with a minimum set of inital connections. The problem seems disappeared. I think the problems come out in connection establishment on randomly repeated open/close. I hope this could help. Denis.
[10 Nov 2004 15:00]
Sune Jakobsson
Hi.
I experience this same error message,
java.sql.SQLException: Communication link failure: java.io.IOException, underlying cause: Unexpected end of input stream
** BEGIN NESTED EXCEPTION **
java.io.IOException
MESSAGE: Unexpected end of input stream
STACKTRACE:
java.io.IOException: Unexpected end of input stream
at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:1405)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:1775)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1020)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:1109)
at com.mysql.jdbc.Connection.execSQL(Connection.java:2030)
at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:1563)
at VoteSessionStore.checkCodeword(VoteSessionStore.java:652)
at VoteSessionManager.setupVoteSession(VoteSessionManager.java:142)
at Parser.parseSMS(Parser.java:173)
at Poller.eternalLoop(Poller.java:91)
at Main.main(Main.java:80)
with this code after 8 hours.
public boolean checkCodeword(String codeword){
if(DEBUG > 3)System.out.println("Check if codeword:" + codeword + " exists in DB, " + Calendar.getInstance().getTime().toString() );
String SQLQuery =
"SELECT Count(*) FROM VoteSession WHERE VSCodeword='" +
codeword + "'";
try {
if(connection.isClosed()){
connection = getNewConnection();
}
PreparedStatement checkCodeword =
connection.prepareStatement(SQLQuery);
ResultSet rs = checkCodeword.executeQuery();
rs.next();
if(rs.getInt("Count(*)") < 1){
return false; //Codeword doesn't exist
}
else{
return true; //Codeword does exist
}
} catch (SQLException e){
if (DEBUG > 4)
e.printStackTrace();
return true;
}
}
and
private Connection getNewConnection() {
try {
Class.forName(databaseDriver);
connection = DriverManager.getConnection(databaseAddr, username , password);
return connection;
} catch (Exception e) {
if (DEBUG > 4)
e.printStackTrace();
return null;
}
}
Please advice why the isClosed() fails if the connection has been idle overnight?
Where is this 8 hour connection timeout described?
This is the MySQL Connector/J 3.0.9-stable (formerly MM.MySQL) version running on a Linux reidun 2.4.18-14 #1 Wed Sep 4 13:35:50 EDT 2002 i686 i686 i386 GNU/Linux with java version "1.4.2_06"
Regards Sune
[28 Mar 2014 12:10]
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.
Description: Connector/J intermittently throws an IOException with the message "Unexpected end of input stream." After this occurs, every query on that connection causes an exception. This appears to happen when a PreparedStatement is "reused" according to the JDBC documentation, using the PreparedStatement.clearParameters method. It also happens when there is more than one statement open on a connection at a time. Here is the top of the stack trace: java.io.IOException: Unexpected end of input stream at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:1405) at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:1775) at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1020) at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:1109) at com.mysql.jdbc.Connection.execSQL(Connection.java:2030) at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java: 1563) How to repeat: The bug is intermittent and there is no reliable way of recreating it, however try re-using a PreparedStatement by calling the "clearParameters" method.