Startup time and RAM usage differences for TR 4 #76

degrown · 2023-01-27T20:52:11Z

Hi,
on my computer (macbook pro 2017, 2.8 GHz, 16 GB, macOS 12.2) I've consistently this data (I report here timings related to a precise run, but the values are about the same every time):

TR 3.7.0 (JRE embedded):

startup time (from click to Overview page visibility): 8/10 seconds
RAM usage:
at startup: 314.7 MB
after 1 hour idle: 315.0 MB
after 2 hour idle: 334.1 MB
maximum levels around 400/500MB in various conditions

TR 4.0.0 beta1 (JRE 17 Temurin)

startup time (from click to Overview page visibility): 1min 20sec
RAM usage:
at startup 557.4 MB
after 1 hour idle 572.0 MB
after 2 hours idle 627.4 MB
after 3 hours idle 672.5 MB
after 5 hours idle 698.3 MB
maximum levels around 900MB/1GB

ursjoss · 2023-01-28T16:30:29Z

Conformed, also ion Linux. There's probably quite a bunch of smaller and bigger contributors to this problem and defintely a lot to improve over time.

But I guess the biggest effect is that - seemingly - with current NetBeans, the cache dir is not set in the same way as with the Netbeans version that was used for developig thinking rock 3.7.0.

With a properly set cache dir, the first launch of the application will be taking a similar time, but subsequent launches will be much quicker. I'll creat a PR to set the directory, which will hopefully be sufficient to close this ticket.

Of course, with additional topics addressing cleanups and small improvements, we should keep performance (both time and memory) in mind and further finetune the application to be more efficient.

…sequent starts of app The default_cachedir is set to DEFAULT_CACHDIR_ROOT, which will be in folder tr-4.0 within: - Mac: "${HOME}/Library/Caches/trgtd" - Linux: "${HOME}/.cache/trgtd/" Not sure where it is on windows.

RadekCap · 2023-01-29T19:24:33Z

Confirmed, also on Linux?

Can you share exact numbers?

In my case,
3.7.1, from Enter in Spotlight to displaying Overview 18.5 s, Java: 1.8.0; Java HotSpot(TM) 64-Bit Server VM 25.0-b70.
and 4 beta from Enter in a Terminal to displaying overview 14.5 s, Temurin, Java: 17.0.5; OpenJDK 64-Bit Server VM 17.0.5+8.

MacOS 13.2, M1.

I'll measure it later on RHEL.

ursjoss · 2023-01-29T19:37:07Z

@RadekCap I suspect that you have installed thinking rock in a directory where your user has write permissions and therefore managed to create the cache directory. In my case I had installed into /opt/tr. The Cache Dir that was evaluated by the launch script resulted in a path where my user does not have write permission. Therefore the cache dir was not writable and subsequent launches could not profit from it.

Can you grep your log file for "Cache Directory" and show the path chosen?

ursjoss · 2023-01-29T22:14:08Z

The stats for me (Arclinux with kernel 6.1.8-arch1-1):

3.7.0

1.8.0_362; OpenJDK 64-Bit Server VM 25.362-b09

Three subsequent starts (starting with a deleted cache):

81 s, 44 s, 41s

4.0.0.beta.1

17.0.6; OpenJDK 64-Bit Server VM 17.0.6+10

With Cache Dir /opt (non-writable, before this PR)

Three subsequent starts:

114 s, 116 s, 114s

With Cache Dir ~/.cache/trgtd/tr-4.0 (writable - starting with a deleted cache)

Three subsequent starts:

114 s, 62 s, 56 s

RadekCap · 2023-01-30T19:24:30Z

@RadekCap I suspect that you have installed thinking rock in a directory where your user has write permissions and therefore managed to create the cache directory.

That's right.

ursjoss · 2023-01-31T07:11:40Z

@RadekCap I suspect that you have installed thinking rock in a directory where your user has write permissions and therefore managed to create the cache directory.

That's right.

You might have the following directories and files scattered in your installation (home?) directory:

With the PR, they would sit neatly in ~/.cache/trgtd/tr-4.0/.

RadekCap · 2023-01-31T12:28:02Z

Yes, they're there :(

ursjoss · 2023-01-31T12:43:31Z

@RadekCap Does the PR help in your case?

RadekCap · 2023-01-31T12:44:49Z

yes, all the mess is in the cache folder.

…hes of the application (#77) * fix(perf): [#76] Set default_cachedir to speed up subsequent starts of app The default_cachedir is set to DEFAULT_CACHDIR_ROOT, which will be in folder tr-4.0 within: - Mac: "${HOME}/Library/Caches/trgtd" - Linux: "${HOME}/.cache/trgtd/" Not sure where it is on windows. * aligns the default_userdir to use DEFAULT_USERDIR_ROOT - Mac: "${HOME}/Library/Application Support/trgtd/tr-4.0" - Linux: "${HOME}/.trgtd/tr-4.0"

degrown · 2023-01-31T20:10:42Z

I don't know if I can think this issue as fully closed.
Even if it's fully true that @ursjoss has successfully solved the startup/caches issue, nothing has been said about RAM usage as for now.
However, even if I've installed the "speedied up" version only few minutes ago, it seems that RAM usage could have been positively affected too.
I'll let you choose if open another investigation issue for RAM usage, or close everything and move on; in my opinion we at least should have a ticket where we remind ourselves to compare RAM usages from 3.7 and from 4.0 between going final.

ursjoss · 2023-01-31T21:55:48Z

I created a separate ticket #78 to handle the memory part of this ticket.

RadekCap · 2023-02-01T06:44:09Z

Still, a minute startup seems horrible to me. I do not have it, even with the cache removed.

@ursjoss Do you have any idea why are my startup so fast? Yes, I still have trgtd folder directly in my home directory.

ursjoss · 2023-02-01T06:49:21Z

Let's compare the size of the datafile...

RadekCap · 2023-02-01T06:52:04Z

Do you think parsing is the bottleneck. It could be.

3 MB in my case.

RadekCap · 2023-02-01T06:53:39Z

@ursjoss Do you see the same very slow startup from Netbeans as well? Netbeans has a profiler - https://netbeans.apache.org/kb/docs/java/profiler-intro.html

ursjoss · 2023-02-01T07:36:53Z

My data file has a size of roughly 1.1M - containing 2897 lines.

I started it three times with the time command, closed it as soon as I saw the application loaded. The time also contains the graceful shutdown time of roughly 5 seconds.

________________________________________________________
Executed in   25.85 secs    fish           external
   usr time   31.42 secs    0.00 micros   31.42 secs
   sys time    0.84 secs  349.00 micros    0.84 secs

________________________________________________________
Executed in   29.14 secs    fish           external
   usr time   34.91 secs  434.00 micros   34.91 secs
   sys time    1.35 secs    0.00 micros    1.35 secs

________________________________________________________
Executed in   22.79 secs    fish           external
   usr time   31.39 secs    0.00 millis   31.39 secs
   sys time    1.20 secs    1.05 millis    1.20 secs

So the actual average startup times of this not very reliable small set of statistics would be around 20-25 seconds.

When we profile the application in the context of ticket #78, we may find bottlenecks that also improves startup-time, who knows.

ursjoss · 2023-02-01T08:33:05Z

On my work computer, the file has 462K - 319 lines.

________________________________________________________
Executed in    8.78 secs    fish           external
   usr time   22.53 secs  455.00 micros   22.53 secs
   sys time    0.59 secs   63.00 micros    0.59 secs

My private laptop (see previous comment) has quite a few more years on it's back, it may simply be too slow to meet nowadays expectations.

degrown · 2023-02-01T10:22:11Z

Just for info: my .trx data file is 1.8MB, and 7271 lines (but this parsing happens on every startup, so maybe you were talking about something else?)

ursjoss · 2023-02-01T11:17:15Z

Just for info: my .trx data file is 1.8MB, and 7271 lines (but this parsing happens on every startup, so maybe you were talking about something else?)

I understood @RadekCap that more than a few seconds startup time - even with caching in place - would be more than he expects.

ursjoss self-assigned this Jan 28, 2023

ursjoss added the performance label Jan 28, 2023

ursjoss mentioned this issue Jan 31, 2023

fix(perf): [#76] Properly set cachedir to speed up (subsequent) launches of the application #77

Merged

RadekCap closed this as completed in #77 Jan 31, 2023

ursjoss mentioned this issue Jan 31, 2023

Profile Memory Usage #78

Open

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Startup time and RAM usage differences for TR 4 #76

Startup time and RAM usage differences for TR 4 #76

degrown commented Jan 27, 2023

ursjoss commented Jan 28, 2023

RadekCap commented Jan 29, 2023

ursjoss commented Jan 29, 2023

ursjoss commented Jan 29, 2023 •

edited

Loading

RadekCap commented Jan 30, 2023

ursjoss commented Jan 31, 2023

RadekCap commented Jan 31, 2023

ursjoss commented Jan 31, 2023

RadekCap commented Jan 31, 2023

degrown commented Jan 31, 2023

ursjoss commented Jan 31, 2023

RadekCap commented Feb 1, 2023

ursjoss commented Feb 1, 2023

RadekCap commented Feb 1, 2023

RadekCap commented Feb 1, 2023

ursjoss commented Feb 1, 2023 •

edited

Loading

ursjoss commented Feb 1, 2023

degrown commented Feb 1, 2023

ursjoss commented Feb 1, 2023

Startup time and RAM usage differences for TR 4 #76

Startup time and RAM usage differences for TR 4 #76

Comments

degrown commented Jan 27, 2023

ursjoss commented Jan 28, 2023

RadekCap commented Jan 29, 2023

ursjoss commented Jan 29, 2023

ursjoss commented Jan 29, 2023 • edited Loading

3.7.0

4.0.0.beta.1

With Cache Dir /opt (non-writable, before this PR)

With Cache Dir ~/.cache/trgtd/tr-4.0 (writable - starting with a deleted cache)

RadekCap commented Jan 30, 2023

ursjoss commented Jan 31, 2023

RadekCap commented Jan 31, 2023

ursjoss commented Jan 31, 2023

RadekCap commented Jan 31, 2023

degrown commented Jan 31, 2023

ursjoss commented Jan 31, 2023

RadekCap commented Feb 1, 2023

ursjoss commented Feb 1, 2023

RadekCap commented Feb 1, 2023

RadekCap commented Feb 1, 2023

ursjoss commented Feb 1, 2023 • edited Loading

ursjoss commented Feb 1, 2023

degrown commented Feb 1, 2023

ursjoss commented Feb 1, 2023

ursjoss commented Jan 29, 2023 •

edited

Loading

ursjoss commented Feb 1, 2023 •

edited

Loading