Page 1 of 1

Slow startup of cached application ?

Posted: 04 Jun 2020, 11:39
by Th3WalkingDad
Hi.

I'm investigating slow startup on my own (OWS 1.1.7).
Got similar point with that issue : https://github.com/karakun/OpenWebStart/issues/152 , like "much" jars to be checked (about 95).
It's mandatory for the client to be up to date (so cannot use <update check="background"/>). It's hardly feasible to add version also. :-/.
Same application in cache is starting in 25-30 secs with OWS/JRE11 while in 2 seconds with JWS/JRE8, with latency of 40ms.

There an interesting comment from @sclassen on April 22th :
> Downloading is done in 6 parallel threads.


What I've observed so far on my own:
- with OWS 1.1.7 Windows10 VM, the checking of the jars (HEAD) seems to be done sequencially on a single connection.
Image

On top of the uncompressible latency (say 40ms), there's a somehow important delay between each request (100-200ms). The consequence is a jar checking speed about 4-5 jars/second for me.
Image


- with JWS 8u202 Windows 10 host, the checking is done on 5-6 different connections, and there's almost no time between each request on the same connection (<10ms). Here there's a jar checking speed of 15 jars/second on each connection.
Image


There's an easy factor 15 speedup startup for JWS for me.

I've noticed high CPU consumption (on a 2 core VM) during OS loading, that could be reduced by hiding console and disabling logs (20% speedup **jar checking speed**).... but that's a concern also, if there's almost CPU hog with a **single** HTTP cnx .
Image


Has anyone observed this ?
I'll go on posting my investigation finding here if any.
The problem is maybe on my side...

Re: Slow startup of cached application ?

Posted: 05 Jun 2020, 08:50
by Hendrik Ebbers
Hi,

Thank you very much for this detailed description. Issues like this help us a lot to make OWS a better product.

From my point of view you describe 2 different issues:

- speed of JAR download and check
- CPU usage for logging & console

We currently doing some rework for the Jar handling and class loading. Therefore we already released a 3.0.0-alpha version. Maybe you can check if this already solves some of the issues about the Jar download & check. You can find the binaries here: https://github.com/karakun/OpenWebStart ... 0.0-alpha1
It would be an important feedback for us to know if this version will work better for you.

The CPU usage is new for us and we need to investigate in that area.

Hendrik

Re: Slow startup of cached application ?

Posted: 05 Jun 2020, 17:09
by Th3WalkingDad
Hi,

Some info. I didn't notice before, but OWS if sending a 'simple' HEAD, while JWS if sending a HEAD with "If-Modified-Since".
The result is different : OWS gets some info about the resources and an HTTP 200 - OK , while JWS gets a laconic HTTP 304 : "Not Modified" (and that's indeed only what we need.
Image

Also, but that's maybe not important, for each resource checked, OWS is not sending any the JSESSIONID cookie that is set on *each* reply.
For JWS, after the 1st or 2nd reply (so 3-4 HEAD are still on the way), all the nexts HEAD will have a given JSESSIOND set.
That probably no a big deal, as the server (it's the same), is always answering fast (creation a JSESSIONID is fast).

=========================

About the 3.0.0alpha, that's strange but with the same jnlp used previously (indeed sent back with application/x-java-jnlp-file MIME) I get that error:

Code: Select all

net.sourceforge.jnlp.LaunchException: Fatal: Read Error: Could not read or parse the JNLP file ...
....
Caused by: java.lang.RuntimeException: java.lang.IllegalStateException: Could not locate a suitable JRE description in the JNLP file for the underlying execution environment. The system properties detected are as follows: (locale: en_US, OS: Windows 10, OS arch: amd64, Java version: 1.8.0_242)
In jnlp, j2se version is "11+" . That is working with 1.1.7. Tried 11.0* , 11*, 11.0+. the same.
What is working : 1.8+ !? (<== and that's only at that time that AdopOpenJDK 11.0.6 was loaded. Set as prefered vendor)

There's this warning :

Code: Select all

- your JRE - 1.8.0_242 - does not match requested JRE - 11+
with the "non working" j2SE version...

============================

As I'm testing in VM, I've made a counter test to exclude the VM impact. On the same VM as 3.0.0alpha (registered with only jnlpx), I've installed Oracle JRE 8u202, save the jnlpx as jnlp and ... I confirm the start of the cached application in 2.5 seconds with JWS... while 3.0.0alpha is taking around 40sec (with *FULL* log and console displayed) ... but "ONLY" 10 seconds with no log and console disabled (and 22 sec with console displayed but no log):
Image

Final users needn't to have the console displayed, but log / console looks to have a real impact..

Indeed the great flow of logs in console reminds me I used to shrink DOS windows that have to display much data ... to avoid as many refresh of screen as possible and speed up transfer for example. I've made the test here. As soon as the console windows are displayed, I reduce their height. The loading drop from 22 to 17 sec...
uhm ...wait... is display (and especially moving down logs in a window) so important.
==> In the VM settings, I checked "Accelerated 3D Graphics" and made another test ==> 16 seconds with consoles and full log (9 without).
Image


===============

Summary:
1) Log and console if activated, consume some CPU and could slow down loading (and maybe operation in general) during log scroll down, particularly if some hardware speedup is not set (where's the 3D here BTW :roll: ????).
==> Suggested possible easy workaround : be able to choose if message are displayed by default on console opening (checkbox "Show message")
If you're interested in logs... *then* you display them when needed ?!

2) There still the use of a single connection (?!) to load sequencialy the jars/ressources.
With the display speedup "improvement" :oops: , the time between the reply and the next request is now 25-35ms (it's 5-15 ms for JWS). So that's OK
Image


Yeah, CPU problem was on my side...

Re: Slow startup of cached application ?

Posted: 11 Jun 2020, 19:35
by Th3WalkingDad
>Yeah, CPU problem was on my side...
Well part of it: when the log refreshes on screen.

Now check-out the possible ITW downloadindicator update impact on that thread : https://github.com/karakun/OpenWebStart/issues/152

Image

Less CPU may speedup loading... and reduce time between jar checking IMHO.

Re: Slow startup of cached application ?

Posted: 11 Jun 2020, 21:10
by Stephan Classen
we are currently looking into this and have found at least one source of unnecessary CPU usage related to logging.

Re: Slow startup of cached application ?

Posted: 12 Jun 2020, 07:54
by Th3WalkingDad
Thank you for this !
I feel the impact, by order of priority, is something like :
- check jar in cache on more than one connection
- reduce CPU used by ITW downloadIndicator
- reduce CPU for log
But every step in the right direction is a valuable step ! ;)

Re: Slow startup of cached application ?

Posted: 05 Aug 2020, 11:34
by Hendrik Ebbers
For OpenWebStart 1.2.0 we implemented a new download indicator (see https://github.com/karakun/OpenWebStart/pull/294/files) and support parallel download of JARS (see https://github.com/AdoptOpenJDK/IcedTea-Web/pull/682). I assume that this will solve a lot of issues that are mentioned in this thread. We will release 1.2.0 at 18.08.2020 and show the new features in our free webinar: viewtopic.php?f=9&t=125