[HARMONY-2914] [classlib][archive][eut] RFE: java.util.zip.ZipFile(File file) wastes file handlers on Linux

• Type: Wish
• Status: Open
• Priority: Minor
• Resolution: Unresolved
• Component/s: Classlib
• Environment: Linux (SLES9), ia32
• Assignee: Unassigned
• Reporter: Nina Rinskaya
• Created: 28/Dec/06 10:42
• Updated: 19/Dec/07 13:38

Description

During Eclipse Unit Tests runs evaluation I've encountered an issue that looks like file handlers waste/leak on Linux when opening new zip (jar) file (using java.util.zip.Zipfile(File file) constructor): unlike RI (Sun), Harmony takes and doesn't releases file handlers when opening zip (jar) files. When working with large application with thousands of plugins and jar files in the classpath, the OS file handlers limit can be reached very quickly as it happens with some Eclipse Unit Tests on Harmony.

The issue can be workarounded (and I did it in EUT) by calling GC each time we expect many zip/jar files opened.

Note, JRockit 1.5 behaves almost in the same way as Harmony (goes out of file handlers and starts throwing IOException), but Sun works ok. I don't know how they did it, but it would be great if we make it work too.

Here is the simple way to reproduce the issue:

1. Create 'tmp' subdirectory in the working directory, and copy any jar file 100 times under '$i.jar' names into 'tmp' subdirectory.
2. Set low open files limit: ulimit -n 60 (reproducible with any limit actually)
3. Compile and run the following test (FileTest.java):

--------------------------------
import java.io.*;
import java.util.zip.ZipFile;

public class FileTest {
public static Object[] oo = new Object[100];
public void testB() {
for (int i=0; i<100; i++) {
try

{ oo[i] = new ZipFile(new File("tmp/"+i+".jar")); }

catch (IOException ioe)

{ ioe.printStackTrace(); System.out.println("Failed on iteration " + i); return; }

}
System.out.println("OK");
}
public static void main(String[] args)

{ FileTest ft = new FileTest(); ft.testB(); }

}

---------------------------------

Output on Harmony (looks like SIGABRT is caused by some VM actions during exit with open files limit reached - can also be a problem) :

java.util.zip.ZipException: archive.24
at java.util.zip.ZipFile.openZip(ZipFile.java:120)
at java.util.zip.ZipFile.<init>(ZipFile.java:111)
at java.util.zip.ZipFile.<init>(ZipFile.java:71)
at FileTest2.testB(FileTest2.java:9)
at FileTest2.main(FileTest2.java:18)
Failed on iteration 12
java: /export/users/nrinskay/harmony_build/trunk/working_vm/vm/vmcore/src/util/linux/signals_ia32.cpp:254: void* find_stack_addr(): Assertion `!err' failed.
SIGABRT in VM code.
Stack trace:
Warning: Cannot get modules info, no symbolic information will be provided
1: ?? (??:-1)
<end of stack trace>
Aborted
----------------------------

Output on JRockit 1.5:

java.io.IOException: Error opening file
at java.util.zip.ZipFile.open(Ljava.lang.String;I)I(Unknown Source)
at java.util.zip.ZipFile.<init>(Ljava.io.File;I)V(Unknown Source)
at java.util.zip.ZipFile.<init>(Ljava.io.File;)V(Unknown Source)
at FileTest2.testB()V(FileTest2.java:9)
at FileTest2.main([Ljava.lang.String;)V(FileTest2.java:20)
Failed on iteration 45
------------------------------------

Output on Sun 1.5:

OK
------------------------

I used strace to compare system calls logs for Sun 1.5, JRockit 1.5 and Harmony (see below). I'm not sure how it works, but Sun releases open files handles just after opening zip/jar files and never goes out of the limit.

Sun:
-----------------------------
stat64("tmp/0.jar",

{st_mode=S_IFREG|0644, st_size=2676, ...}) = 0
open("tmp/0.jar", O_RDONLY|O_LARGEFILE) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=2676, ...}

) = 0
_llseek(3, 0, [2676], SEEK_END) = 0
mmap2(NULL, 2676, PROT_READ, MAP_SHARED, 3, 0) = 0x89e9a000
close(3) = 0
stat64("tmp/1.jar",

{st_mode=S_IFREG|0644, st_size=2676, ...}) = 0
open("tmp/1.jar", O_RDONLY|O_LARGEFILE) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=2676, ...}

) = 0
_llseek(3, 0, [2676], SEEK_END) = 0
mmap2(NULL, 2676, PROT_READ, MAP_SHARED, 3, 0) = 0x89e9b000
close(3) = 0
stat64("tmp/2.jar",

{st_mode=S_IFREG|0644, st_size=2676, ...}) = 0
open("tmp/2.jar", O_RDONLY|O_LARGEFILE) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=2676, ...}

) = 0
_llseek(3, 0, [2676], SEEK_END) = 0
mmap2(NULL, 2676, PROT_READ, MAP_SHARED, 3, 0) = 0x89e9c000
close(3)
-----------------------------

We see "close" call for each opened file.

Jrockit:
--------------------------
open("tmp/0.jar", O_RDONLY|O_LARGEFILE) = 15
fstat64(15,

{st_mode=S_IFREG|0644, st_size=2676, ...}) = 0
pread(15, "PK\5\6\0\0\0\0\5\0\5\0005\1\0\0)\t\0\0\0\0", 22, 2654) = 22
pread(15, "PK\1\2\24\0\24\0\10\0\10\0\23\230\2325\0\0\0\0\2\0\0\0"..., 309, 2345) = 309
stat64("tmp/1.jar", {st_mode=S_IFREG|0644, st_size=2676, ...}

) = 0
open("tmp/1.jar", O_RDONLY|O_LARGEFILE) = 16
fstat64(16,

{st_mode=S_IFREG|0644, st_size=2676, ...}) = 0
pread(16, "PK\5\6\0\0\0\0\5\0\5\0005\1\0\0)\t\0\0\0\0", 22, 2654) = 22
pread(16, "PK\1\2\24\0\24\0\10\0\10\0\23\230\2325\0\0\0\0\2\0\0\0"..., 309, 2345) = 309
stat64("tmp/2.jar", {st_mode=S_IFREG|0644, st_size=2676, ...}

) = 0
open("tmp/2.jar", O_RDONLY|O_LARGEFILE) = 17
fstat64(17,

{st_mode=S_IFREG|0644, st_size=2676, ...}) = 0
pread(17, "PK\5\6\0\0\0\0\5\0\5\0005\1\0\0)\t\0\0\0\0", 22, 2654) = 22
pread(17, "PK\1\2\24\0\24\0\10\0\10\0\23\230\2325\0\0\0\0\2\0\0\0"..., 309, 2345) = 309
stat64("tmp/3.jar", {st_mode=S_IFREG|0644, st_size=2676, ...}

) = 0
open("tmp/3.jar", O_RDONLY|O_LARGEFILE) = 18
------------------------------

• no "close" call.

Harmony:
------------------------------
open("tmp/0.jar", O_RDONLY) = 48
fcntl64(48, F_GETFD) = 0
fcntl64(48, F_SETFD, FD_CLOEXEC) = 0
read(48, "PK\3\4", 4) = 4
lseek(48, 0, SEEK_SET) = 0
stat64("tmp/0.jar",

{st_mode=S_IFREG|0644, st_size=2676, ...}) = 0
stat64("tmp/0.jar", {st_mode=S_IFREG|0644, st_size=2676, ...}

) = 0
lseek(48, 0, SEEK_END) = 2676
lseek(48, 1652, SEEK_SET) = 1652
read(48, "hH\304D|\254\340\223*g\2*\346u\3339\301\35>\5\265Z2-7v"..., 1024) = 1024
lseek(48, 2345, SEEK_SET) = 2345
read(48, "PK\1\2\24\0\24\0\10\0\10\0\23\230\2325\0\0\0\0\2\0\0\0"..., 313) = 313
stat64("tmp/1.jar",

{st_mode=S_IFREG|0644, st_size=2676, ...}) = 0
open("tmp/1.jar", O_RDONLY) = 49
fcntl64(49, F_GETFD) = 0
fcntl64(49, F_SETFD, FD_CLOEXEC) = 0
read(49, "PK\3\4", 4) = 4
lseek(49, 0, SEEK_SET) = 0
stat64("tmp/1.jar", {st_mode=S_IFREG|0644, st_size=2676, ...}

) = 0
stat64("tmp/1.jar",

{st_mode=S_IFREG|0644, st_size=2676, ...}) = 0
lseek(49, 0, SEEK_END) = 2676
lseek(49, 1652, SEEK_SET) = 1652
read(49, "hH\304D|\254\340\223*g\2*\346u\3339\301\35>\5\265Z2-7v"..., 1024) = 1024
lseek(49, 2345, SEEK_SET) = 2345
read(49, "PK\1\2\24\0\24\0\10\0\10\0\23\230\2325\0\0\0\0\2\0\0\0"..., 313) = 313
stat64("tmp/2.jar", {st_mode=S_IFREG|0644, st_size=2676, ...}

) = 0
open("tmp/2.jar", O_RDONLY) = 50
fcntl64(50, F_GETFD) = 0
fcntl64(50, F_SETFD, FD_CLOEXEC) = 0
read(50, "PK\3\4", 4) = 4
lseek(50, 0, SEEK_SET) = 0
stat64("tmp/2.jar",

{st_mode=S_IFREG|0644, st_size=2676, ...}) = 0
stat64("tmp/2.jar", {st_mode=S_IFREG|0644, st_size=2676, ...}

) = 0
lseek(50, 0, SEEK_END) = 2676
lseek(50, 1652, SEEK_SET) = 1652
read(50, "hH\304D|\254\340\223*g\2*\346u\3339\301\35>\5\265Z2-7v"..., 1024) = 1024
lseek(50, 2345, SEEK_SET) = 2345
read(50, "PK\1\2\24\0\24\0\10\0\10\0\23\230\2325\0\0\0\0\2\0\0\0"..., 313) = 313
stat64("tmp/3.jar",

{st_mode=S_IFREG|0644, st_size=2676, ...}

) = 0
open("tmp/3.jar", O_RDONLY)
---------------------------------

• no "close" call.

Issue Links

• blocks: HARMONY-4109 [M2] umbrella task for 98% pass rate of Eclipse 3.2 unit tests; no regression since M1