Class java.lang.Win32Process is depleting native Win32 process handles
when running on a large Java heap. The Win32 API process handles are
kept until the next minor collection is run. When running on a large
Java heap, Windows may run of out resources before the next minor
collection will appear. What is considered a "large" Java heap is
depending on the machine's load.
The problem is strictly reproducible.
0. Equipment
------------
All tests have been made on a Pentium4 Win2000 SP4 with 512MB of RAM,
only running Windows.
1. Testcase
-----------
The testcase is fairly simple and consists of the following files:
23/08/2005 19:54 31 native.cpp
23/08/2005 20:37 525 Exec.java
24/08/2005 23:32 1,454 make.bat
You'll need sysinternals pslist (www.sysinternals.com/Utilities/PsList.html):
23/05/2003 19:21 86,016 pslist.exe
% more native.cpp
int main() {
return 0;
}
% more Exec.java
class Exec {
public static void main(String args[]) {
int i = 0;
while (true) {
try {
Process p = Runtime.getRuntime().exec("native.exe");
p.waitFor();
p.exitValue();
p.getErrorStream().close();
p.getOutputStream().close();
p.getInputStream().close();
p.destroy();
} catch (Exception e) {
e.printStackTrace();
break;
}
if (i%100 == 0) System.out.println(i);
i++;
} // end while
}
}
2. Compile
----------
Used Borland's free C++ compiler:
E:\>make ccompile
E:\>bcc32 -enative.exe -LC:\bcc55\lib native.cpp
Borland C++ 5.5.1 for Win32 Copyright (c) 1993, 2000 Borland
native.cpp:
Turbo Incremental Link 5.00 Copyright (c) 1997, 2000 Borland
E:\>make compile
E:\>java -version
java version "1.4.2_09"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.4.2_09-b05)
Java HotSpot(TM) Client VM (build 1.4.2_09-b05, mixed mode)
E:\>javac Exec.java
E:\>
3. Run on default config
------------------------
Everything is fine when running on default or small heapsize:
Example: default heapsize:
E:\37443767>make run
E:\37443767>java -server -verbosegc -XX:+PrintGCDetails Exec
0
100
[GC [DefNew: 511K->64K(576K), 0.0033800 secs] 511K->188K(1984K), 0.0036278 secs]
200
[GC [DefNew: 575K->63K(576K), 0.0019318 secs] 700K->323K(1984K), 0.0021575 secs]
300
400
[GC [DefNew: 575K->63K(576K), 0.0014337 secs] 835K->395K(1984K), 0.0016561 secs]
500
600
[GC [DefNew: 575K->63K(576K), 0.0011099 secs] 907K->468K(1984K), 0.0013306 secs]
700
[GC [DefNew: 573K->63K(576K), 0.0012275 secs] 978K->541K(1984K), 0.0015496 secs]
800
900
[GC [DefNew: 575K->63K(576K), 0.0010415 secs] 1053K->612K(1984K), 0.0012650 secs]
1000
[GC [DefNew: 575K->63K(576K), 0.0010423 secs] 1124K->684K(1984K), 0.0012655 secs]
1100
[ ... keeps running forever ]
Terminate batch job (Y/N)? y
Use "pslist.exe" in a second shell window to monitor handle utilisation:
E:\37443767>pslist java
PsList 1.23 - Process Information Lister
Copyright (C) 1999-2002 Mark Russinovich
Sysinternals - www.sysinternals.com
Process information for WIN2000:
Name Pid Pri Thd Hnd Mem User Time Kernel Time Elapsed Time
java 1808 8 10 264 10100 0:00:06.259 0:00:11.125 0:01:06.205
E:\>pslist java
[ ... ]
Process information for WIN2000:
Name Pid Pri Thd Hnd Mem User Time Kernel Time Elapsed Time
java 1808 8 10 334 10100 0:00:06.289 0:00:11.196 0:01:06.645
E:\>pslist java
[ ... ]
Process information for WIN2000:
Name Pid Pri Thd Hnd Mem User Time Kernel Time Elapsed Time
java 1808 8 10 395 10100 0:00:06.309 0:00:11.256 0:01:07.066
E:\>pslist java
PsList 1.23 - Process Information Lister
Copyright (C) 1999-2002 Mark Russinovich
Sysinternals - www.sysinternals.com
Process information for WIN2000:
Name Pid Pri Thd Hnd Mem User Time Kernel Time Elapsed Time
java 1808 8 10 304 10100 0:00:06.319 0:00:11.366 0:01:07.507
E:\>
The handle count seen is within a small range of 250 - 450 handles.
4. Testrow: varying -Xms over -Xms1024m
----------------------------------------
The following tests have been run on 1.4.2_09, while -Xmx1024 was
left unchanged. The following table gives the maximum amount of
handles seen before minor collection used to kick in:
-Xms client server
-----------------------------------
64m 1450 2050
128m 2700 4000
256m 5300 7600
512m 10400 14900
768m 15500 fail
1024m fail fail
default ~500 ~500
-----------------------------------
The minimum number of handles was about 250, seen after
GC (minor collection most times) had run.
5. Failure case
---------------
The failure can be most easily reproduced on the above given machine with
-Xms1024m -Xmx1024m.
E:\37443767>make run
E:\37443767>java -server -Xms1024m -Xmx1024m -verbosegc -XX:+PrintGCDetails Exec
0
[ ... ]
18200
18300
18400
18500
18600
18700
java.io.IOException: CreateProcess: native.exe error=1450
at java.lang.Win32Process.create(Native Method)
at java.lang.Win32Process.<init>(Win32Process.java:66)
at java.lang.Runtime.execInternal(Native Method)
at java.lang.Runtime.exec(Runtime.java:566)
at java.lang.Runtime.exec(Runtime.java:428)
at java.lang.Runtime.exec(Runtime.java:364)
at java.lang.Runtime.exec(Runtime.java:326)
at Exec.main(Exec.java:6)
E:\>
This leads to Windows error 1450 "Insufficient System Resources".
Obviously Windows ran out of process handles.
"pslist" monitor showed that the process just used 18948 handles:
E:\>pslist java
PsList 1.23 - Process Information Lister
Copyright (C) 1999-2002 Mark Russinovich
Sysinternals - www.sysinternals.com
Process information for WIN2000:
Name Pid Pri Thd Hnd Mem User Time Kernel Time Elapsed Time
java 60380 8 10 18948 69112 0:00:10.214 0:00:39.717 0:02:20.782
C:\>pslist java
So, this shows that the Java process piled up for its over 18700 iterations
18948 Windows' handles, until it effectively ran out of Windows' resources.
Most of the handles in use are expected to be Win32 process handles, as the
figures just correspond very nicely.
The exact failure parameters vary with the actual utilisation of the resources
on the machine. It was reported that the limit was already hit by a little over
2000 handles being occupied by the Java process.
6. Documentation
----------------
Looking into Microsoft's documentation for "CreateProcess"
http://msdn.microsoft.com/library/default.asp?url=/library/en-us/dllproc/base/createprocess.asp
------------
"lpProcessInformation
[out] Pointer to a PROCESS_INFORMATION structure that receives identification
information about the new process.
Handles in PROCESS_INFORMATION must be closed with CloseHandle when they are
no longer needed."
------------
So, it is required ("must") to close the handles as soon as they are no longer
needed. The JVM however is stacking up the handles until the objects of type
java.lang.Win32Process get collected.
when running on a large Java heap. The Win32 API process handles are
kept until the next minor collection is run. When running on a large
Java heap, Windows may run of out resources before the next minor
collection will appear. What is considered a "large" Java heap is
depending on the machine's load.
The problem is strictly reproducible.
0. Equipment
------------
All tests have been made on a Pentium4 Win2000 SP4 with 512MB of RAM,
only running Windows.
1. Testcase
-----------
The testcase is fairly simple and consists of the following files:
23/08/2005 19:54 31 native.cpp
23/08/2005 20:37 525 Exec.java
24/08/2005 23:32 1,454 make.bat
You'll need sysinternals pslist (www.sysinternals.com/Utilities/PsList.html):
23/05/2003 19:21 86,016 pslist.exe
% more native.cpp
int main() {
return 0;
}
% more Exec.java
class Exec {
public static void main(String args[]) {
int i = 0;
while (true) {
try {
Process p = Runtime.getRuntime().exec("native.exe");
p.waitFor();
p.exitValue();
p.getErrorStream().close();
p.getOutputStream().close();
p.getInputStream().close();
p.destroy();
} catch (Exception e) {
e.printStackTrace();
break;
}
if (i%100 == 0) System.out.println(i);
i++;
} // end while
}
}
2. Compile
----------
Used Borland's free C++ compiler:
E:\>make ccompile
E:\>bcc32 -enative.exe -LC:\bcc55\lib native.cpp
Borland C++ 5.5.1 for Win32 Copyright (c) 1993, 2000 Borland
native.cpp:
Turbo Incremental Link 5.00 Copyright (c) 1997, 2000 Borland
E:\>make compile
E:\>java -version
java version "1.4.2_09"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.4.2_09-b05)
Java HotSpot(TM) Client VM (build 1.4.2_09-b05, mixed mode)
E:\>javac Exec.java
E:\>
3. Run on default config
------------------------
Everything is fine when running on default or small heapsize:
Example: default heapsize:
E:\37443767>make run
E:\37443767>java -server -verbosegc -XX:+PrintGCDetails Exec
0
100
[GC [DefNew: 511K->64K(576K), 0.0033800 secs] 511K->188K(1984K), 0.0036278 secs]
200
[GC [DefNew: 575K->63K(576K), 0.0019318 secs] 700K->323K(1984K), 0.0021575 secs]
300
400
[GC [DefNew: 575K->63K(576K), 0.0014337 secs] 835K->395K(1984K), 0.0016561 secs]
500
600
[GC [DefNew: 575K->63K(576K), 0.0011099 secs] 907K->468K(1984K), 0.0013306 secs]
700
[GC [DefNew: 573K->63K(576K), 0.0012275 secs] 978K->541K(1984K), 0.0015496 secs]
800
900
[GC [DefNew: 575K->63K(576K), 0.0010415 secs] 1053K->612K(1984K), 0.0012650 secs]
1000
[GC [DefNew: 575K->63K(576K), 0.0010423 secs] 1124K->684K(1984K), 0.0012655 secs]
1100
[ ... keeps running forever ]
Terminate batch job (Y/N)? y
Use "pslist.exe" in a second shell window to monitor handle utilisation:
E:\37443767>pslist java
PsList 1.23 - Process Information Lister
Copyright (C) 1999-2002 Mark Russinovich
Sysinternals - www.sysinternals.com
Process information for WIN2000:
Name Pid Pri Thd Hnd Mem User Time Kernel Time Elapsed Time
java 1808 8 10 264 10100 0:00:06.259 0:00:11.125 0:01:06.205
E:\>pslist java
[ ... ]
Process information for WIN2000:
Name Pid Pri Thd Hnd Mem User Time Kernel Time Elapsed Time
java 1808 8 10 334 10100 0:00:06.289 0:00:11.196 0:01:06.645
E:\>pslist java
[ ... ]
Process information for WIN2000:
Name Pid Pri Thd Hnd Mem User Time Kernel Time Elapsed Time
java 1808 8 10 395 10100 0:00:06.309 0:00:11.256 0:01:07.066
E:\>pslist java
PsList 1.23 - Process Information Lister
Copyright (C) 1999-2002 Mark Russinovich
Sysinternals - www.sysinternals.com
Process information for WIN2000:
Name Pid Pri Thd Hnd Mem User Time Kernel Time Elapsed Time
java 1808 8 10 304 10100 0:00:06.319 0:00:11.366 0:01:07.507
E:\>
The handle count seen is within a small range of 250 - 450 handles.
4. Testrow: varying -Xms over -Xms1024m
----------------------------------------
The following tests have been run on 1.4.2_09, while -Xmx1024 was
left unchanged. The following table gives the maximum amount of
handles seen before minor collection used to kick in:
-Xms client server
-----------------------------------
64m 1450 2050
128m 2700 4000
256m 5300 7600
512m 10400 14900
768m 15500 fail
1024m fail fail
default ~500 ~500
-----------------------------------
The minimum number of handles was about 250, seen after
GC (minor collection most times) had run.
5. Failure case
---------------
The failure can be most easily reproduced on the above given machine with
-Xms1024m -Xmx1024m.
E:\37443767>make run
E:\37443767>java -server -Xms1024m -Xmx1024m -verbosegc -XX:+PrintGCDetails Exec
0
[ ... ]
18200
18300
18400
18500
18600
18700
java.io.IOException: CreateProcess: native.exe error=1450
at java.lang.Win32Process.create(Native Method)
at java.lang.Win32Process.<init>(Win32Process.java:66)
at java.lang.Runtime.execInternal(Native Method)
at java.lang.Runtime.exec(Runtime.java:566)
at java.lang.Runtime.exec(Runtime.java:428)
at java.lang.Runtime.exec(Runtime.java:364)
at java.lang.Runtime.exec(Runtime.java:326)
at Exec.main(Exec.java:6)
E:\>
This leads to Windows error 1450 "Insufficient System Resources".
Obviously Windows ran out of process handles.
"pslist" monitor showed that the process just used 18948 handles:
E:\>pslist java
PsList 1.23 - Process Information Lister
Copyright (C) 1999-2002 Mark Russinovich
Sysinternals - www.sysinternals.com
Process information for WIN2000:
Name Pid Pri Thd Hnd Mem User Time Kernel Time Elapsed Time
java 60380 8 10 18948 69112 0:00:10.214 0:00:39.717 0:02:20.782
C:\>pslist java
So, this shows that the Java process piled up for its over 18700 iterations
18948 Windows' handles, until it effectively ran out of Windows' resources.
Most of the handles in use are expected to be Win32 process handles, as the
figures just correspond very nicely.
The exact failure parameters vary with the actual utilisation of the resources
on the machine. It was reported that the limit was already hit by a little over
2000 handles being occupied by the Java process.
6. Documentation
----------------
Looking into Microsoft's documentation for "CreateProcess"
http://msdn.microsoft.com/library/default.asp?url=/library/en-us/dllproc/base/createprocess.asp
------------
"lpProcessInformation
[out] Pointer to a PROCESS_INFORMATION structure that receives identification
information about the new process.
Handles in PROCESS_INFORMATION must be closed with CloseHandle when they are
no longer needed."
------------
So, it is required ("must") to close the handles as soon as they are no longer
needed. The JVM however is stacking up the handles until the objects of type
java.lang.Win32Process get collected.
- relates to
-
JDK-6334268 (process) Windows Process.exitValue() has poor error handling
- Resolved