Bug #73053 Endless loop in MysqlIO.clearInputStream due to Linux kernel bug
Submitted: 19 Jun 2014 14:20 Modified: 16 Jul 2014 20:11
Reporter: Filipe Silva Email Updates:
Status: Closed Impact on me:
None 
Category:Connector / J Severity:S2 (Serious)
Version: OS:Linux (kernels 3.6 and earlier)
Assigned to: Filipe Silva CPU Architecture:Any

[19 Jun 2014 14:20] Filipe Silva
Description:
This is a branch of Bug#24995 (Socket read locks up other threads) report, from Davi Arnaut's post on Jun 12. There is no proof that this issue is actually related to the original report.

Transcription from Bug#24995:

«[12 Jun 3:04] Davi Arnaut 

Linux kernels version 3.6 and earlier (including 2.6.32) have a bug [1] which makes requests for the amount of available bytes to read in a socket in CLOSE_WAIT state to return 1 even after the EOF has been read.

This bug makes SocketInputStream.available return 1 for sockets in CLOSE_WAIT state and causes a seemly infinite loop in MysqlIO.clearInputStream where it attempts to read from the socket until the number of available bytes reaches 0, but there is nothing to read.

1. https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/commit/?id=a3374c4

Java strack trace of a thread looping in clearInputStream:

   java.lang.Thread.State: RUNNABLE
        at java.net.PlainSocketImpl.socketAvailable(Native Method)
        at java.net.PlainSocketImpl.available(PlainSocketImpl.java:472)
        - locked <0x00007f674094a498> (a java.net.SocksSocketImpl)
        at java.net.SocketInputStream.available(SocketInputStream.java:217)
        at com.mysql.jdbc.util.ReadAheadInputStream.available(ReadAheadInputStream.java:232)
        at com.mysql.jdbc.MysqlIO.clearInputStream(MysqlIO.java:961)
        at com.mysql.jdbc.ServerPreparedStatement.serverPrepare(ServerPreparedStatement.java:1690)
        - locked <0x00007f672c938970> (a java.lang.Object)
        at com.mysql.jdbc.ServerPreparedStatement.<init>(ServerPreparedStatement.java:427)
        at com.mysql.jdbc.JDBC4ServerPreparedStatement.<init>(JDBC4ServerPreparedStatement.java:44)
        [reset omitted]

Sample trace of the systems calls in the above thread:

        ioctl(405, FIONREAD, [1])               = 0
        ioctl(405, FIONREAD, [1])               = 0
        ioctl(405, FIONREAD, [1])               = 0
        ioctl(405, FIONREAD, [1])               = 0
        ioctl(405, FIONREAD, [1])               = 0
        ioctl(405, FIONREAD, [1])               = 0

[17 Jun 0:13] Filipe Silva

Hi Davi,

Thanks for your feedback. It would be nice to have some more detail on this. Full stack traces and perhaps some profiling info, if possible.

Have you tried to include the changes you suggest in your own Connector/J build?

[17 Jun 17:55] Davi Arnaut

The stacktrace down to application specific code:

   java.lang.Thread.State: RUNNABLE
        at java.net.PlainSocketImpl.socketAvailable(Native Method)
        at java.net.PlainSocketImpl.available(PlainSocketImpl.java:472)
        - locked <0x00007f674094a498> (a java.net.SocksSocketImpl)
        at java.net.SocketInputStream.available(SocketInputStream.java:217)
        at com.mysql.jdbc.util.ReadAheadInputStream.available(ReadAheadInputStream.java:232)
        at com.mysql.jdbc.MysqlIO.clearInputStream(MysqlIO.java:961)
        at com.mysql.jdbc.ServerPreparedStatement.serverPrepare(ServerPreparedStatement.java:1690)
        - locked <0x00007f672c938970> (a java.lang.Object)
        at com.mysql.jdbc.ServerPreparedStatement.<init>(ServerPreparedStatement.java:427)
        at com.mysql.jdbc.JDBC4ServerPreparedStatement.<init>(JDBC4ServerPreparedStatement.java:44)
        at sun.reflect.GeneratedConstructorAccessor52.newInstance(Unknown Source)
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
        at com.mysql.jdbc.ServerPreparedStatement.getInstance(ServerPreparedStatement.java:355)
        at com.mysql.jdbc.ConnectionImpl.serverPrepareStatement(ConnectionImpl.java:4880)
        [application specific trace omitted]

What kind of profiling info do you need?

> Have you tried to include the changes you suggest in your own Connector/J build?

We simply removed the clearInputStream function.

[18 Jun 11:25] Alexander Soklakov

Hi Davi,

Thank you for such interesting finding!

According to kernel bug fix, the problem occurs when application consumed all bytes from socket. That means on Java side the InputBuffer is in EOF state and can't be reused.

We have a bug with consulting InputStream.available() at this stage, there shouldn't be any value of such attempt, the method should be refactored.

As for your stack trace, it seems the only possible reason is that your code tries to reuse connection when it is in closing state, maybe by the other side.

BTW, do you think this problem is related to initial one reported here?

[18 Jun 17:41] Davi Arnaut

> As for your stack trace, it seems the only possible reason is that your code tries to reuse connection when it is in closing state, maybe by the other side.

Yes, like, connection timeout or connection killing, where the server closes its side of the connection.

> BTW, do you think this problem is related to initial one reported here?

Not sure. Based on the other comments, seemed to be the closest one that was still open.»

How to repeat:
Please consult Bug#24995 to additional information.
[16 Jul 2014 20:11] Daniel So
Added the following entry into the Connector/J 5.1.32 changelog:

"A bug in the Linux kernel version 3.6 and earlier caused the MysqlIO.clearInputStream() method to enter an endless loop. This fix changes the way the looping condition is evaluated, in order to avoid the problem."