Bug #68400 useCompression=true and connect to server, zip native method cause out of memory
Submitted: 16 Feb 2013 8:06 Modified: 10 Jul 2013 21:26
Reporter: aaron liu Email Updates:
Status: Closed Impact on me:
None 
Category:Connector / J Severity:S2 (Serious)
Version:5.1.X OS:Solaris
Assigned to: Alexander Soklakov
Tags: OutOfMemory, useCompression, zip native

[16 Feb 2013 8:06] aaron liu
Description:
Exception in thread "com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0" java.lang.OutOfMemoryError
        at java.util.zip.Deflater.init(Native Method)
        at java.util.zip.Deflater.<init>(Deflater.java:117)
        at java.util.zip.Deflater.<init>(Deflater.java:134)
        at com.mysql.jdbc.MysqlIO.doHandshake(MysqlIO.java:1347)
        at com.mysql.jdbc.ConnectionImpl.connectWithRetries(ConnectionImpl.java:2172)
        at com.mysql.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:2127)
        at com.mysql.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:774)
        at com.mysql.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:371)
        at com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:289)
        at com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:134)
        at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:182)

How to repeat:
Native method cause outofmemory because JVM did not execute GC.  

Suggested fix:
I checked MysqlIO source code.
this.deflater.end() isn't invoked, why?
[16 Feb 2013 8:07] aaron liu
http://www.devguli.com/blog/eng/java-deflater-and-outofmemoryerror/
[16 Feb 2013 8:36] aaron liu
X
[22 Feb 2013 17:23] Sveta Smirnova
Thank you for the report.

According to http://docs.oracle.com/javase/1.4.2/docs/api/java/util/zip/Deflater.html#end%28%29: 

public void end()

    Closes the compressor and discards any unprocessed input. This method should be called when the compressor is no longer being used, but will also be called automatically by the finalize() method. Once this method is called, the behavior of the Deflater object is undefined. 

So this method should be called automatically.

Please send us complete test case which uses c/J and shows the problem.
[1 Mar 2013 3:31] aaron liu
I know that GC can trigger realase native resource. but when native method is invoked many times before GC, it may be native heap overflow because Deflater object is small but its native heap is bigger. it is difficult to trigger GC by Deflater object.
so I think end() method is invoked to release native resouce immediately when compression operation finish. because we does not make sure to trigger GC before native heap overflow. 
please check the test case. Thanks!
[1 Mar 2013 3:35] aaron liu
Test case result:

java -Xms3500m -Xmx3500m -XX:+PrintGCDetails -XX:PermSize=1m -cp ./mysql-connector-java-5.1.13-bin.jar:./JDBCCompressTest.class: JDBCCompressTest
testSize = 63000
Exception in thread "main" java.lang.OutOfMemoryError
        at java.util.zip.Deflater.init(Native Method)
        at java.util.zip.Deflater.<init>(Deflater.java:117)
        at java.util.zip.Deflater.<init>(Deflater.java:134)
        at com.mysql.jdbc.MysqlIO.doHandshake(MysqlIO.java:1347)
        at com.mysql.jdbc.ConnectionImpl.connectWithRetries(ConnectionImpl.java:2172)
        at com.mysql.jdbc.ConnectionImpl.createNewIO(ConnectionImpl.java:2127)
        at com.mysql.jdbc.ConnectionImpl.<init>(ConnectionImpl.java:774)
        at com.mysql.jdbc.ConnectionImpl.getInstance(ConnectionImpl.java:371)
        at com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:289)
        at java.sql.DriverManager.getConnection(DriverManager.java:525)
        at java.sql.DriverManager.getConnection(DriverManager.java:171)
        at JDBCCompressTest.getConnection(JDBCCompressTest.java:27)
        at JDBCCompressTest.main(JDBCCompressTest.java:45)
[1 Mar 2013 3:36] aaron liu
Test Case

Attachment: JDBCCompressTest.java (application/octet-stream, text), 1.56 KiB.

[1 Mar 2013 6:23] aaron liu
Connector/J

Attachment: mysql-connector-java-5.1.13-bin.jar (application/octet-stream, text), 749.50 KiB.

[4 Mar 2013 23:06] Sveta Smirnova
Thank you for the test case.

Which version of Java do you use? I can notice memory increase, but garbage collection happens from time to time and program does not crash due to "Out of memory" error.

$ java -version
java version "1.6.0_24"
OpenJDK Runtime Environment (IcedTea6 1.11.5) (rhel-1.50.1.11.5.el6_3-x86_64)
OpenJDK 64-Bit Server VM (build 20.0-b12, mixed mode)
[4 Mar 2013 23:07] Sveta Smirnova
Please also make sure you use latest version of c/J: 5.1.22
[7 Mar 2013 5:47] aaron liu
java -version
java version "1.5.0_32"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.5.0_32-b05)
Java HotSpot(TM) Server VM (build 1.5.0_32-b05, mixed mode)

I think that trigger GC to release native resource, it is not reasonable because native resource is allocated Perm Heap, GC don't care about Perm Heap size. So it is reasonable that end() method is invoked to release native resouce immediately when compression finished.

Thanks!
[12 Mar 2013 14:49] Alexander Soklakov
Hi Aaron,

I wasn't able to reproduce OOM but I would set this bug as verified because I see continued growth of used native memory during your test case run.

We keep a one live Deflater object per connection for performance reasons. The alternative is to create new Deflater for each compressed packet or per request or per something else, and it's too expensive by common sense. But we should profile this case.

What surely we can do is to call this.deflater.end() during connection close process to release native resource immediately for dead connections.
[13 Mar 2013 7:06] aaron liu
Thanks for your reply!
I agree with your opinion.
[13 May 2013 10:00] Alexander Soklakov
Great thanks to Dominic Tootell for locating the problem http://forums.mysql.com/read.php?39,586107,586107

Deflater.end() didn't completely resolved the problem, the core reason of this memory leak is CompressedInputStream holding the reference to connection object. This reference cleanup in CompressedInputStream.close() removes the leak.
[13 May 2013 10:02] Alexander Soklakov
Patch for bug#68400

Attachment: bug68400.diff (text/x-patch), 2.57 KiB.

[14 May 2013 13:47] Alexander Soklakov
Patch with WeakReference

Attachment: bug68400.diff (text/x-patch), 9.53 KiB.

[10 Jul 2013 21:26] Daniel So
Added entry to the changelog of Connector/J 5.1.26:

An out of memory error occured when the compression protocol was enabled with the connection option useCompression=true. This fix stops the memory leak that caused the error by making sure that CompressedInputStream releases its reference to the connection object when the input stream closes.