[jboss-jira] [JBoss JIRA] Commented: (JBVFS-159) Native memory leak due to ZipEntryInputStream

[Samuel Cai (JIRA)]

    [ https://jira.jboss.org/browse/JBVFS-159?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12536495#action_12536495 ] 

Samuel Cai commented on JBVFS-159:
----------------------------------

Marko, thanks again for you test.

Last week I did several tests and found the root cause. I'll attach all materials in a zip. Also I'll list all testings I've done, there were some interesting findings.

1. I wrote a java class to utilize VFS directly, see the Test1.java, also modified ZipFileWrapper.java to allow system property jboss.vfs.useNativeStream to use ZipInputStream instead of ZipEntryInputStream. By doing this on a directory (has 81 jars, total 48M), I can clearly see process size issue when using ZipEntryInputStream, but not if use ZipInputStream.
Since this is single thread and noReaperOverride is true, ZipFile was closed every time after one ZipEntry was processed, additional log proved this.
Note, I skipped processing directory, if not, I can see process size issue even using ZipInputStream, just always a little better than using ZipEntryInputStream. So there seems have some other issue in method recomposeZipAsInputStream, but no time to check it. This is an interesting finding.

2. Based on test #1, we can see the difference is, if use ZipEntryInputStream, steam may be left opened, ZipFile is closed (according to JDK, which then close all of the input streams previously returned by invocations of the {@link #getInputStream getInputStream} method). If use ZipInputStream, ZipFile isn't closed (maybe after GC), instead I only close the input streams.
This is clearly a JDK related issue, so I wrote a pure test (Test2.java) which only uses JDK's API. It reads three arguments, first one is the jar/zip file it'll process, second is the loop times, third is whether close stream before closing zip file. For example (Test2.java is in leakdetector.jar):
/data/jdk/bin/java -cp leakdetector.jar Test2 /tmp/vfs-nested.tmp/80d72123_jboss-xa-jdbc.jar 10000 false
/data/jdk/bin/java -cp leakdetector.jar Test2 /tmp/vfs-nested.tmp/80d72123_jboss-xa-jdbc.jar 10000 true
I wrote a simple script(jps_test.sh) to record process size (VSZ) and RSS, run it in another window first, here is the result:
False:
Logging jps info
Mon Jun 21 00:33:39 PDT 2010
1257728 48548
Logging jps info
Mon Jun 21 00:33:40 PDT 2010
1339648 94380
Logging jps info
Mon Jun 21 00:33:41 PDT 2010
1422752 141176
Logging jps info
Mon Jun 21 00:33:42 PDT 2010
1508768 188620
Logging jps info
Mon Jun 21 00:33:43 PDT 2010
1589476 238240
True:
Logging jps info
Mon Jun 21 00:34:17 PDT 2010
1195024 16436
Logging jps info
Mon Jun 21 00:34:18 PDT 2010
1195024 20476
Logging jps info
Mon Jun 21 00:34:19 PDT 2010
1196784 26280
Logging jps info
Mon Jun 21 00:34:20 PDT 2010
1196784 30728
Logging jps info
Mon Jun 21 00:34:21 PDT 2010
1196784 33912

3. Based on #2, we can see if don't close stream before closing ZipFile, will have native memory leak. JAVA uses ZLIB for zip native operation, we tested three version of libz.so: 1.2.1.2 (come with OS), 1.2.3 (in JBoss's native), 1.2.5 (I compiled by myself), no luck. My coworker tested IBM JDK, no luck. All were done on Redhat, if want to test other Linux, need more time.

Based on above, could you try the Test2.java on your local Linux machine? If can reproduce, then means we have to close stream before closing ZipFile.
(Since I can easily reproduce locally with pure test, sorry I can't try you test, also due to requirement maven setup on Linux server, I right now only setup local windows)
Note, I found several old bugs/issues for JDK, related to native memory leak of zip under multi-core CPU system, if you can't reproduce, maybe you can try on that kind of machine.

If you still can't reproduce, then maybe our system is different to others, I may file a bug to JAVA to see if they can help.

> Native memory leak due to ZipEntryInputStream
> ---------------------------------------------
>
>                 Key: JBVFS-159
>                 URL: https://jira.jboss.org/browse/JBVFS-159
>             Project: JBoss VFS
>          Issue Type: Bug
>      Security Level: Public(Everyone can see) 
>    Affects Versions: 2.1.2.GA
>         Environment: Redhat (not sure what version) 2.6.9-78.ELsmp
> JBoss 5.1.0.GA
> JDK 1.6.0_20
> JVM parameter:
> -XX:+PrintGCTimeStamps -XX:+PrintGCApplicationStoppedTime -verbose:gc -Dfile.encoding=iso-8859-1 -server -Djava.net.preferIPv4Stack=true -Doracle.jdbc.V8Compatible=true -Dsun.rmi.dgc.client.gcInterval=3600000 -Dsun.rmi.dgc.server.gcInterval=3600000 -Dnetworkaddress.cache.ttl=300 -Xss128k -Xmn500m -Dorg.apache.jasper.runtime.BodyContentImpl.LIMIT_BUFFER=true -XX:+PrintGCDetails -XX:PermSize=256m -XX:MaxPermSize=256m -Xms1500m -Xmx1500m -XX:+HeapDumpOnOutOfMemoryError -XX:+UseConcMarkSweepGC 
>            Reporter: Samuel Cai
>            Assignee: Marko Strukelj
>         Attachments: VFSZipMemoryTestCase.java
>
>
> We used to use JBoss 4.2.1.GA and JDK 1.6.0_11, and trying JBoss 5.1.0.GA and JDK 1.6.0_20 these days.
> I found the process size is more larger than before, 2.5G~2.9G compared to 1.9G.
> I was thinking this was a bug of JBoss AS, then filed https://jira.jboss.org/browse/JBAS-8066
> After these days investigation, I think this is a memory leak in VFS, maybe only happen on our specific environment.
> I tried a change on class org.jboss.virtual.plugins.context.zip.ZipFileWrapper, method openStream:
> From:
> ZipEntryInputStream zis = new ZipEntryInputStream(this, is);
> return zis;
> To:
> //ZipEntryInputStream zis = new ZipEntryInputStream(this, is);
> //return zis;
> return is;
> That is, don't use ZipEntryInputStream, let any class/method invoking openStream to close zipFile's inputStream immediatelly.
> ZipFile will be in open status, but all steams will be closed well.
> This makes the process size down to same as JBoss 4's. I tried going through first 3 pages of site, no problems. May need QA team to test more.
> Btw, I tried updating VFS to 2.1.3.SP1/2.2.0.M4/3.0.0.CR5, first two have same size issue, third one couldn't start.

-- 
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: https://jira.jboss.org/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira