JDK-7113700 : Cold Start JVM/Applet Slow to instantiate init() method
  • Type: Bug
  • Component: deploy
  • Sub-Component: plugin
  • Affected Version: 6u29
  • Priority: P3
  • Status: Closed
  • Resolution: Duplicate
  • OS: windows_xp
  • CPU: x86
  • Submitted: 2011-11-19
  • Updated: 2012-03-20
  • Resolved: 2011-11-30
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
JDK 8
8Resolved
Related Reports
Duplicate :  
Description
FULL PRODUCT VERSION :
>java -version
java version "1.6.0_29"
Java(TM) SE Runtime Environment (build 1.6.0_27-b07)
Java HotSpot(TM) Client VM (build 20.2-b06, mixed mode, sharing)


ADDITIONAL OS VERSION INFORMATION :
Windows XP [Version 5.1.2600]
IE7 or IE8

EXTRA RELEVANT SYSTEM CONFIGURATION :
Host Name:                 Ask
OS Name:                   Microsoft Windows XP Professional
OS Version:                5.1.2600 Service Pack 3 Build 2600
OS Manufacturer:           Microsoft Corporation
OS Configuration:          Member Workstation
OS Build Type:             Multiprocessor Free
Registered Owner:          NVIDIA
Registered Organization:   NVIDIA
Product ID:                76487-641-3050913-23128
Original Install Date:     5/13/2010, 3:43:10 PM
System Up Time:            0 Days, 9 Hours, 24 Minutes, 56 Seconds
System Manufacturer:       Dell Inc.
System Model:              Latitude E6400
System type:               X86-based PC
Processor(s):              1 Processor(s) Installed.
                           [01]: x86 Family 6 Model 23 Stepping 10 GenuineIntel ~2527 Mhz
BIOS Version:              DELL   - 27d90c15
Windows Directory:         C:\WINDOWS
System Directory:          C:\WINDOWS\system32
Boot Device:               \Device\HarddiskVolume1
System Locale:             en-us;English (United States)
Input Locale:              en-us;English (United States)
Time Zone:                 (GMT-08:00) Pacific Time (US & Canada)
  Total Physical Memory:     3,572 MB
Available Physical Memory: 1,543 MB
Virtual Memory: Max Size:  2,048 MB
Virtual Memory: Available: 2,008 MB
Virtual Memory: In Use:    40 MB
Page File Location(s):     C:\pagefile.sys
Domain:                    nvidia.com
Logon Server:              \\HQDC103
Hotfix(s):                 398 Hotfix(s) Installed.
                           [01]: File 1
....
...
..
                           [189]: Q147222
                           [190]: M2572067 - Update
                           [191]: M979906 - Update
                           [192]: S867460 - Update
                           [193]: KB925674 - Update
                           [194]: KB937060 - Update
                           [195]: Q954430
                           [196]: Q973688
                           [197]: IDNMitigationAPIs - Update
                           [198]: NLSDownlevelMapping - Update
                           [199]: KB929399
                           [200]: KB2378111_WM9
                           [201]: KB952069_WM9
                           [202]: KB954155_WM9
                           [203]: KB968816_WM9
                           [204]: KB973540_WM9
                           [205]: KB975558_WM8
                           [206]: KB978695_WM9
                           [207]: KB936782_WMP11
                           [208]: KB939683
                           [209]: KB954154_WM11
                           [210]: KB941569
                           [211]: KB2183461-IE7 - Update
                           [212]: KB2360131-IE7 - Update
                           [213]: KB2416400-IE7 - Update
                           [214]: KB2482017-IE7 - Update
                           [215]: KB2497640-IE7 - Update
                           [216]: KB2530548-IE7 - Update
                           [217]: KB2544521-IE7 - Update
                           [218]: KB2559049-IE7 - Update
                           [219]: KB2586448-IE7 - Update
                           [220]: KB938127-v2-IE7 - Update
                           [221]: KB958215-IE7 - Update
                           [222]: KB960714-IE7 - Update
                           [223]: KB972260-IE7 - Update
                           [224]: KB974455-IE7 - Update
                           [225]: KB976325-IE7 - Update
                           [226]: KB976749-IE7 - Update
                           [227]: KB978207-IE7 - Update
                           [228]: KB980182-IE7 - Update
                           [229]: KB982381-IE7 - Update
                           [230]: KB2564958 - Update
                           [231]: KB971513 - Update
                           [232]: MSCompPackV1 - Update
                           [233]: KB898461 - Update
                           [234]: KB915865 - Update
                           [235]: KB926139-v2
                           [236]: KB2079403 - Update
                           [237]: KB2115168 - Update
                           [238]: KB2121546 - Update
                           [239]: KB2124261 - Update
                           [240]: KB2141007 - Update
                           [241]: KB2158563 - Update
                           [242]: KB2160329 - Update
                           [243]: KB2229593 - Update
                           [244]: KB2259922 - Update
                           [245]: KB2279986 - Update
                           [246]: KB2286198 - Update
                           [247]: KB2290570 - Update
                           [248]: KB2296011 - Update
                           [249]: KB2296199

NetWork Card(s):           4 NIC(s) Installed.
                           [01]: Intel(R) WiFi Link 5300 AGN
                                 Connection Name: Wireless Network Connection
                           [02]: Cisco Systems VPN Adapter
                                 Connection Name: Local Area Connection 2
                           [03]: Intel(R) 82567LM Gigabit Network Connection
                                 Connection Name: Local Area Connection
                                 DHCP Enabled:    Yes
                                 DHCP Server:     172.20.148.30
                                 IP address(es)
                                 [01]: 172.16.201.120
                           [04]: 1394 Net Adapter
                                 Connection Name: 1394 Connection
                                 DHCP Enabled:    Yes
                                 DHCP Server:     N/A
                                 IP address(es)

A DESCRIPTION OF THE PROBLEM :
On a cold system, even a simple Hello World Applet will initialize very slow ~2 minutes before console and jvm logging begin.

The init() is not being called until 1-2 minutes.

This can be exhibited even with thick applications like Eclipse, if a JRE/JVM has previously been instantiated then the time is less than 5 seconds, if however a JVM has not previously been instantiated the processes will take 1-2 orders of magnitude longer to initialize.


STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
On a cold system, even a simple Hello World Applet will initialize very slow ~2 minutes before console and jvm logging begin.

The init() is not being called until 1-2 minutes.

This can be exhibited even with thick applications like Eclipse, if a JRE/JVM has previously been instantiated then the time is less than 5 seconds, if however a JVM has not previously been instantiated the processes will take 1-2 orders of magnitude longer to initialize.


STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
Deploy simple/tutorial ���HelloWorld��� to a local IIS instance, then deploy Applet class.
Run the Applet web page on a system that has not had a JRE/JVM instantiated since last reboot.

The simple Hello World Applet will take 1-3 minutes to instantiate.

Even the java console will not load and the java icon will also not show in the system taskbar.

Once the Console instantiates the Applet will init() within 1-2 seconds.

All subsequent executions will init() within 1-2 or actually milli-seconds.

Does not matter if the Applet has been cached or not, there is some additional
latency if the Applet has not been cached, but negligible when considering the
1-3 minutes to wait for init() method to be called.

If you abort the Applet and reload it will generally init() within a few seconds, thus
considering this might be a waiting/locking condition, but stack traces do not indicate
this is the case. Stack traces have been provided.


EXPECTED VERSUS ACTUAL BEHAVIOR :
EXPECTED -
The Applet should instantiate on a cold system within 2-4X of a system that has a warm "previously instantiated" JRE.

See this url:
http://international.download.nvidia.com/GPUA/doc/JavaStalling/HelloWorld.NoStall.10152011.swf

ACTUAL -
See this url:
http://international.download.nvidia.com/GPUA/doc/JavaStalling/HelloWorld.NoStall.10152011.swf


ERROR MESSAGES/STACK TRACES THAT OCCUR :
See stack traces:
http://international.download.nvidia.com/GPUA/doc/JavaStalling/StackTarces.HellowWorld.Stallied.20111015.A.txt



REPRODUCIBILITY :
This bug can be reproduced always.

---------- BEGIN SOURCE ----------
Loadable Applet page:
http://international.download.nvidia.com/GPUA/doc/JavaStalling/HelloWorldApplet/bin/HelloWorld.Akamai.html


See http://international.download.nvidia.com/GPUA/doc/JavaStalling/HelloWorldApplet/bin/HelloWorld.java

  See also, Sun tutorials:

import javax.swing.JApplet;
import javax.swing.SwingUtilities;
import javax.swing.JLabel;
import java.util.Calendar;
import java.util.Date;
import java.util.Locale;
import java.util.TimeZone;
import java.util.GregorianCalendar;
import java.text.SimpleDateFormat;

public class HelloWorld extends JApplet {
    //Called when this applet is loaded into the browser.
    public void init() {
        //Execute a job on the event-dispatching thread; creating this applet's GUI.
        try {
            SwingUtilities.invokeAndWait(new Runnable() {
				SimpleDateFormat dateFormat = new SimpleDateFormat("MMM dd yyyy HH:mm:ss",Locale.ENGLISH);
                public void run() {
                	
    				Calendar theCalendar = new GregorianCalendar(TimeZone.getTimeZone("GMT"));
    				Date creationDate = theCalendar.getTime();
                    JLabel lbl = new JLabel("Hello World:"+this.dateFormat.format(creationDate));
                    add(lbl);
                }
            });
        } catch (Exception e) {
            System.err.println("createGUI didn't complete successfully");
        }
    }
}

---------- END SOURCE ----------

CUSTOMER SUBMITTED WORKAROUND :
None, affecting thousands of users per day, we are attributing 15% of a critical capability failure to this condition.

Production solution can be exhibited here:
http://www.geforce.com/GamesandApps/games/battlefield-3/GPUAnalyzer
See the "CHECK NOW" functionality.

This functionality has been utilized by millions of users world-wide, any help that could be provided in providing a resolution would be greatly appreciated.


SUPPORT :
YES

Comments
EVALUATION I can reproduce the issue locally if %TEMP% dir has lots of files when jre6 is used. For the applet scenario this is because of 6705872 that is fixed in JRE7. I also verified we are not reading %TEMP% if JRE 7 update 1 is used (using applet from submitter) and PML files from submitter prove the same. Moreover, JRE7 log only takes about 50s (comparing to 2 minutes for jre 6) and part of this time (10+ sec) seem to be idle (waiting for user to accept security dialog?). Therefore i beleive original problem is resolved in JRE 7 and closing this issue as duplicate of 6705872.
30-11-2011

WORK AROUND Cleanup temp folder.
24-11-2011

EVALUATION Submitter confirmed that c:\temp contained 8500+ files and that cleaning this folder improves startup performance to expected level.
24-11-2011

EVALUATION Based on PML logs provided by submitter it seem java.exe is spending over a minute reading content of c:\temp and it seem c:\temp contains a lot of files. It is not clear why we need to read full content of c:\temp folder and we should not be slowed down by this anyways. Asked submitter to validate if clearing c:\temp will help to resolve the issue.
23-11-2011