Bug 550878 - Performance: repository state cache for decorators
Summary: Performance: repository state cache for decorators
Status: RESOLVED FIXED
Alias: None
Product: EGit
Classification: Technology
Component: UI (show other bugs)
Version: 5.5   Edit
Hardware: All All
: P3 enhancement (vote)
Target Milestone: 5.6   Edit
Assignee: Project Inbox CLA
QA Contact:
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2019-09-09 02:20 EDT by Thomas Wolf CLA
Modified: 2019-11-17 17:42 EST (History)
1 user (show)

See Also:


Attachments
ReadAttributePerf.java (918 bytes, text/plain)
2019-10-17 05:13 EDT, Marc R. Hoffmann CLA
no flags Details
ReadAttributePerf.java (990 bytes, text/plain)
2019-10-17 07:48 EDT, Marc R. Hoffmann CLA
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Thomas Wolf CLA 2019-09-09 02:20:53 EDT
EGit decorators are slow because they access git files frequently (git configs, HEAD, etc.) Similar to bug 544600: investigate how repository state could be cached such that the number of file accesses is reduced.

One idea might be to re-use the RepositoryStateCache added in bug 544600, but then that cache must also be reset on index diff changes, at least for the affected repositories, and such a (partial) reset must occur before the decorator runs.

The cache would also need to cache more things. Branch tracking status is particularly expensive and is re-evaluated for each project.
Comment 1 Marc R. Hoffmann CLA 2019-10-01 10:18:16 EDT
In follow-up to my test scenarios for bug 456996 I made a probably quite naive experiment and modified org.eclipse.jgit.util.SystemReader.getUserConfig() in the following way: 

    long ts = System.currentTimeMillis();
    if (ts - lastUserConfig > 1000) {
        if (c.isOutdated()) {
	    LOG.debug("loading user config {}", userConfig); //$NON-NLS-1$
            c.load();
        }
        lastUserConfig = ts;
    }

This reduces my test scenario from thousands of accesses of .gitcongif to just one per second.

Probably this is the wrong location and covers only the .gitconfig case. Maybe FileSnapshot is the better place to implement some caching. Not sure though whether this mechanism os only in place to monitor changes done by other processes (where from mym point of view a latency of 1 second or so would be acceptable) or whether changes done by JGit itself needs to be immediately reflected by FileSnapshot (in this case this aproach will not work).
Comment 2 Thomas Wolf CLA 2019-10-16 16:38:54 EDT
Can you give the average time to run java.nio.file.Files.readAttributes(path, BasicFileAttributes.class, LinkOption.NOFOLLOW_LINKS) on your ~/.gitconfig on your network drive home directory?
Comment 3 Marc R. Hoffmann CLA 2019-10-17 05:13:32 EDT
Created attachment 280291 [details]
ReadAttributePerf.java
Comment 4 Marc R. Hoffmann CLA 2019-10-17 05:15:41 EDT
(In reply to Thomas Wolf from comment #2)
> Can you give the average time to run
> java.nio.file.Files.readAttributes(path, BasicFileAttributes.class,
> LinkOption.NOFOLLOW_LINKS) on your ~/.gitconfig on your network drive home
> directory?

Sure. I run the attached test:

  Iterations: 1000
  Avg. Nanos: 31642854
  Max. Nanos: 84398080

So average is over 30ms (I have to admit that out network setup could be improved, but this is a story beyond our control).
Comment 5 Thomas Wolf CLA 2019-10-17 05:20:34 EDT
Please include a little warm-up. The first call is likely to have taken (much) longer than the others because classes are loaded on demand, and because there may be JIT compilation be involved.

Running a little loop with a few iterations (say, 50) before the 1000 timed iterations may change the outcome.
Comment 6 Thomas Wolf CLA 2019-10-17 05:24:23 EDT
BTW: I'm just trying to get a ballpark figure so i can simulate this on my Mac with an appropriate Thread.sleep() to check what effects various caching strategies have.
Comment 7 Marc R. Hoffmann CLA 2019-10-17 07:48:13 EDT
Now with 50 iterations of warmup. It doesn't change much:

Iterations: 1000
Avg. Nanos: 32043544
Max. Nanos: 88648512

It's even slower, but probably it depends on the current network load.
Comment 8 Marc R. Hoffmann CLA 2019-10-17 07:48:43 EDT
Created attachment 280292 [details]
ReadAttributePerf.java
Comment 9 Eclipse Genie CLA 2019-10-26 13:59:49 EDT
New Gerrit change created: https://git.eclipse.org/r/151660
Comment 10 Eclipse Genie CLA 2019-10-27 05:29:44 EDT
New Gerrit change created: https://git.eclipse.org/r/151669
Comment 11 Eclipse Genie CLA 2019-10-27 14:00:06 EDT
Gerrit change https://git.eclipse.org/r/151669 was merged to [master].
Commit: http://git.eclipse.org/c/egit/egit.git/commit/?id=cca58bb545e144e9cc521f3786785feacb8f1953
Comment 12 Eclipse Genie CLA 2019-11-06 03:20:48 EST
New Gerrit change created: https://git.eclipse.org/r/152109
Comment 13 Eclipse Genie CLA 2019-11-06 03:20:54 EST
New Gerrit change created: https://git.eclipse.org/r/152111
Comment 14 Thomas Wolf CLA 2019-11-06 09:30:55 EST
@Marc: if your repo doesn't have submodules you might give https://git.eclipse.org/r/#/c/152110/ (temporary update site at https://ci.eclipse.org/egit/job/egit.gerrit/754/artifact/org.eclipse.egit.repository/target/repository/ ) a try.

Would be interested in knowing if that improves the situation noticeably. Also of interest: do you notice any glitches such as something not updating when it should (and does in EGit 5.5.1)? (I didn't, but that doesn't mean much.)

There's still many calls to FileUtils.getAttributes(), but far less. Most are not for ~/.gitconfig, though, and cannot be avoided. The ones for ~/.gitconfig should be reduced quite a bit. There's still a little room for further reducing them, but it would be useful to know whether this already helps.
Comment 15 Marc R. Hoffmann CLA 2019-11-08 05:36:05 EST
@Thomas: I patched our Eclipse installation with the update site (very helpful!) and tested it in our environment on a very large Git repo.

I'm impressed! Even with .gitconfig on the network share I haven't noticed any UI freezes. Also when I did some jstack samples I have never seen a EGit/JGit trace in main thread (which was always the case before).

I will ask some colleagues to work with your patch.

Thanks for your great work, Thomas!
Comment 16 Thomas Wolf CLA 2019-11-11 03:53:17 EST
Nice to hear that it works well enough even for your large repo.

> I will ask some colleagues to work with your patch.

Things to watch out are in particular decorations not updating or updating wrongly. Or the staging view not updating as it should. (Staging view updates can be delayed by a running build though; that's unrelated and has always been that way.)
Comment 17 Eclipse Genie CLA 2019-11-12 10:13:00 EST
Gerrit change https://git.eclipse.org/r/152109 was merged to [master].
Commit: http://git.eclipse.org/c/egit/egit.git/commit/?id=0a2a6a4a54d0a7b3507641a261499566d80e1ae9
Comment 18 Eclipse Genie CLA 2019-11-15 18:55:58 EST
Gerrit change https://git.eclipse.org/r/151660 was merged to [master].
Commit: http://git.eclipse.org/c/jgit/jgit.git/commit/?id=a227dc3ba0e0a426657b84cea148174e8a315b31
Comment 19 Eclipse Genie CLA 2019-11-17 14:02:18 EST
Gerrit change https://git.eclipse.org/r/152111 was merged to [master].
Commit: http://git.eclipse.org/c/egit/egit.git/commit/?id=ac1320338a87f1945a9d8fb97ecc8bbecef31a1e