Skip to main content

Why does Java Webstart take so long to start downloading the application?

34 replies [Last post]
cowwoc
Offline
Joined: 2003-08-24

I used Netbeans to launch a local Java Webstart application and I see the following:

"Java6 ..." logo comes up in under a second
[4-8 seconds elapse]
"Downloading application" displays for a second
My application begins running

My question is what is "Java6 ..." doing for 4-8 seconds?

The HD light barely flickers during this time, however I noticed 1 out of my 4 CPU cores registers 85% activity. Two questions there:

1) What could possibly be so cpu-intensive when the application hasn't launched yet? Maybe "Java6 ..." just a GIF and the actual JVM is taking 4-8 seconds to launch?

2) Secondly, why isn't Webstart using multiple cores? I mean, if you could launch 4 times faster by using all 4 of my cores that would sure help ;)

Thanks,
Gili

Reply viewing options

Select your preferred way to display the comments and click "Save settings" to activate your changes.
rgibson_2
Offline
Joined: 2006-02-28

A (presumably) related symptom is that launching the cache viewer
jdk1.6.0_10/bin/javaws -viewer
takes twice or 3 times as long as
jdk1.6.0_06/bin/javaws -viewer

I've attached HPROF sampling profiles.

cowwoc
Offline
Joined: 2003-08-24

Roger,

Please download http://bbs.darktech.org/webstart-cache.zip (38MB) and let me know when this is done. If anyone else downloads this file I will be forced to take it offline sooner, so please guys leave this file for Roger alone :)

Here is what I see:

- If I rename "deployment.dirty" to C:\Users\Gili\AppData\LocalLow\Sun\Java\Deployment then running the testcase causes "Java6..." to display 3 dots on average.
- If I rename "deployment.clean" to C:\Users\Gili\AppData\LocalLow\Sun\Java\Deployment then running the testcase causes "Java6..." to display 1 dot on average.

This gets worse the more times I run the application (say one dot per 5 minutes I try this). In order to reproduce the problem faster I modified the testcase to depend on:

JFreeChart
javamail
jaxen
joda-time

but you can generally speaking throw any JAR files at it on your end. The more JAR files, the quicker performance will degrade. I hope the snapshot of my cache directory will give you a hint of what is wrong.

Gili

rogyeu
Offline
Joined: 2006-07-30

done.

rogyeu
Offline
Joined: 2006-07-30

I have opened a CR for this issue: CR 6720393.

I seem to be able to reproduce it with 6u10-b25 only, but not b26 or later. Need to investigate further on this.

I have included both review ID under this CR. Thank you for reporting the issue and the information provided!

-- RY

rogyeu
Offline
Joined: 2006-07-30

Gilli,

I am trying to reproduce the issue with your sample. But I cannot reproduce it. Do you have metrics about the usual time and longest time your provided code launches? I encountered zombie process left behind if I try to launch your app many times (http://bugs.sun.com/view_bug.do?bug_id=6719329), but not able to reproduce the long startup time issue.

Regards,
RY

cowwoc
Offline
Joined: 2003-08-24

Roger,

I am still trying to find a more reliable way to reproduce the problem but Vista makes it very difficult. I'm trying to avoid SuperFetch and disk access to "C:\System Volume Information" from interfering with these tests :) In the meantime I found another bug which might be related.

Up until now I have been running the application sequentially but I just tried running a few instances concurrently and I ran into a race-condition bug. If you launch the same application multiple times simultaneously you will get the following exception:

java.io.EOFException: encoding.error.not.xml
at com.sun.deploy.xml.XMLEncoding.decodeXML(XMLEncoding.java:48)
at com.sun.javaws.jnl.XMLFormat.parse(XMLFormat.java:62)
at com.sun.javaws.jnl.LaunchDescFactory.buildDescriptor(LaunchDescFactory.java:59)
at com.sun.javaws.jnl.LaunchDescFactory.buildDescriptor(LaunchDescFactory.java:68)
at com.sun.javaws.Launcher.updateFinalLaunchDesc(Launcher.java:266)
at com.sun.javaws.Launcher.prepareToLaunch(Launcher.java:167)
at com.sun.javaws.Launcher.launch(Launcher.java:111)
at com.sun.javaws.Main.launchApp(Main.java:306)
at com.sun.javaws.Main.continueInSecureThread(Main.java:210)
at com.sun.javaws.Main$1.run(Main.java:107)
at java.lang.Thread.run(Thread.java:619)

Once that happens, the Webstart cache is corrupt and the application cannot be run again. It is worth noting that when I opened up the "Java Cache Viewer" it showed same JNLP file twice under the "resources" tab, something which I thought was supposed to be impossible. The only way I could fix the problem was by running "javaws.exe -uninstall". Should I file a bug report for this one too?

Gili

rb5563
Offline
Joined: 2008-06-12

Gili,
I recommend you please do post that bug.
Btw, may name is Roger also, but I know you are addressing RY :-)
... RB

cowwoc
Offline
Joined: 2003-08-24

How confusing ;)

So which one of you is Roger from Sun?

Okay, I've posted a bug report to BugParade. It's Review ID is 1279784.

rb5563
Offline
Joined: 2008-06-12

I am not from Sun, so if one of us it, it's RY
...RB

ghaneman
Offline
Joined: 2006-11-09

Re the "failure to launch and leave no trail", I can reproduce this problem with any webstart app using b27. Although the problem is intermittent and may be related to the other issues discussed in this thread, I have filed a bug, 6726716, for this specific problem that should appear in a couple of days (unless they determine it is a duplicate).

rb5563
Offline
Joined: 2008-06-12

I see one link that isn't 6u10. This is (for me anyway) only a 6u10 issue. 6u6 works fine.

I see a reference to 6u10 b26. I am on b25 and don't see any b26 out yet. Can I assume that was a typo?

I see the problem in IE7 and Firefox 3.

I cannot provide a test case because I cannot reliably reproduce it, especially not now.

I just spent half the day trying to figure out why Vista would not let me rename my cache directory even though I have every priv and I could not find anything that admitted to having anything in the cache opened.

I ended up cleaning up my Vista and stopping about 20-30 startup programs and services.

After the reboot I could rename cache (not a shock), did so, and download is fast. I haven't gotten up to about 20 times yet. We'll see if it changes.

So right now I cannot reproduce the problem.

I actually have another problem now, which is some applications download fine, but fail to launch and leave no trail. I am going to study the JNLP files to see if there is any difference between those that work and those that don't. More on that later if I can define the problem.

There are no large images involved.

...RB

cowwoc
Offline
Joined: 2003-08-24

rb5563,

Process Explorer allows you to find out which process has a file or directory locked: http://technet.microsoft.com/en-us/sysinternals/bb896653.aspx

Gili

rb5563
Offline
Joined: 2008-06-12

Yes, and it said nothing was opened. Vista first popped up the window requesting confirmation, then the UAC window asking for permission, and then finally an error saying "You need permission". It does not say anything is locked (it would be nice if it gave me a "file access conflict" if that was the case). I own the directory, have every permission, and have unselected the permission interlocks with parent folders. This too is not reproducible at will, but is also obviously not a Java issue.

rgibson_2
Offline
Joined: 2006-02-28

The problem I'm seeing goes away if the Java cache is emptied. Is it the case for you?
Try running
javaws -uninstall
or just renaming or deleting your cache directory (C:\Users\username\AppData\LocalLow\Sun\Java\Deployment by default under Vista I think).

fatbatman
Offline
Joined: 2004-12-24

I wonder if this is related to the slow downloading of remote images/files I mentioned at http://forums.java.net/jive/thread.jspa?threadID=42599&tstart=0

rgibson_2
Offline
Joined: 2006-02-28

Does emptying your cache help?

rogyeu
Offline
Joined: 2006-07-30

Which browser are you using? What is your network connection setting?

Are you seeing similar issue as:
http://bugs.sun.com/view_bug.do?bug_id=6506138

Thanks,
RY

cowwoc
Offline
Joined: 2003-08-24

I don't think it's the same bug.

I only ever use FireFox, and on my machine both FF and IE have proxies completely disabled.

rogyeu
Offline
Joined: 2006-07-30

Could you please provide a test case where we can reproduce the issue?

Thanks,
RY

cowwoc
Offline
Joined: 2003-08-24

Hi Roger,

Here is what worked for me:

WebstartBug.java
-----------------------------------
public class Main
{
public static void main(String[] args)
{
System.exit(1);
}
}

launch.jnlp
------------------------------------



WebstartBug
Gili

WebstartBug
WebstartBug










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

The JAR dependencies seem to be the key. If you run the program 20 times or so you will notice the startup times increasing (slowly). I am expecting the "Java6..." animation to display for at most 1 second. It adds one dot per animation so eventually I see the startup time go from one dot all the way up to 3 dots (after about 20 runs) and continue to grow the more I run it.

Again, all files are running from a local codebase and the delay occurs *before* Webstart begins downloading updates from the server.

Gili

rb5563
Offline
Joined: 2008-06-12

Gili,
When you say "here is what worked" you mean this is what reproduces the problem/issue, per RY's request, right? Or do you mean this solved it? When you say the "JAR dependencies seem to be the key" how do you mean that? Could you elaborate? Btw, when I was getting the problem, it was in all phases (Java 6 splash with the dot dot dot, and download (which would stall), and also launching the application post download).
...RB

cowwoc
Offline
Joined: 2003-08-24

"here is what worked" means here is a testcase for reproducing the problem.

It seems that when you have "JAR dependencies" the cache seems to take longer at the "Java6..." phase. If you have a program without any dependencies I'm not sure the bug will occur (or if it does it would take 100s of runs to notice it). The more dependencies you have, the easier it seems to be to reproduce it.

I don't know about the download stall because as I mentioned in my case I'm using a local codebase. My personal testcase is only for the "Java6..." part. It could very well be that solving my problem will solve it for you as well but you need to come up with a testcase for reproducing it 100% of the time.

rgibson_2
Offline
Joined: 2006-02-28

Gili,
Your observation that running the same application 20 times (serially, I suppose, not concurrently) causes slowdown intrigues me, are you noticing that your cache directory grows over this period? I would have thought that after downloading the first time nothing should change, right?
Robert

cowwoc
Offline
Joined: 2003-08-24

I would have thought the same, but apparently this isn't the case.

rgibson_2
Offline
Joined: 2006-02-28

What I'm wondering is if the cache grows or just changes structure in some way.

cowwoc
Offline
Joined: 2003-08-24

Comparing the two cache directories I would say the following:

- Many new *.idx files added (though they are tiny - 221 bytes)
- *.lap file indicates that the dirty cache saw 55 launches of the testcase whereas the clean one only saw 3.

I believe the IDX files are the culprit because I see 55 idx files in the bad cache versus 3 in the good cache. It looks as if Webstart adds a new file per run and the overhead of processing an ever-growing list of indexes (regardless of how small each one is) is killing it :)

What I find even more interesting is that the bug is CPU-bound not disk-bound.

rb5563
Offline
Joined: 2008-06-12

You didn't mention O/S

I am seeing extreme slowness on Windows Vista but no problem on XP.

Downlod keeps going into "stalled" state and takes over a minute when it should take about 3 sconds.

Anyone else seeing this?

cowwoc
Offline
Joined: 2003-08-24

I am running Vista 64-bit on my end. I can't comment on the download time because I'm running a local Webstart application (file://...)

When you think about it, that makes it even worse :) Webstart has no excuse to take so long to start up when all my components are local. I would further point out that if I invoke "javaws -uninstall", run the same local application 20 times the problem comes back. At this point the cache should only contain references to my local application so it isn't clear why it would become slow.

Secondly, I think taking 3 seconds to start up or download a local application (if it's already cached) is unreasonable. Ideally Webstart should start in under a second, two seconds being the limit. Anything longer than a second is very noticeable from an end-user point of view so it should really be the exception not the rule.

cowwoc
Offline
Joined: 2003-08-24

I have some good news and bad news.

The good news is that running "javaws -uninstall" reduced the delay to 1 second, so we know the problem is somehow related to the Java Webstart cache.

The bad news is that I just destroyed my reproducible testcase so I can't track down the exact source of the problem.

I think we can safely assume that as the cache grows, the delay somehow increases. Maybe the algorithm doesn't scale well as the number of entries increases? That being said, I am really worried by this behavior because I had almost no applications in my cache (I rarely use Webstart).

Is it possible that Webstart's cache tries contacting the web servers of each entry in the cache on startup? I really hope not, but that would definitely explain what I've been seeing.

Has anyone else been able to reproduce this?

rgibson_2
Offline
Joined: 2006-02-28

We have some beta testers here who are having the same problem. Extreme slowness when starting applets and Web Start applications which disappears when "javaws -uninstall" is run.

If any Sun people are interested, I have asked one of our users not to apply the fix, so I have a broken system available for experimentation.

rgibson_2
Offline
Joined: 2006-02-28

Bug filed, review ID 1279673

cowwoc
Offline
Joined: 2003-08-24

Oops, I also filed a bug report ;) Mine has review ID 1279666

Hopefully Sun will merge the two.

rgibson_2
Offline
Joined: 2006-02-28

Did you link this thread in your bug report? I forgot ...

cowwoc
Offline
Joined: 2003-08-24

Yes, I linked to this thread.