Bug 544600 - Performance: cache more git repository state on selection changes
Summary: Performance: cache more git repository state on selection changes
Status: RESOLVED FIXED
Alias: None
Product: EGit
Classification: Technology
Component: UI (show other bugs)
Version: 5.3   Edit
Hardware: All All
: P3 normal (vote)
Target Milestone: 5.6   Edit
Assignee: Project Inbox CLA
QA Contact:
URL:
Whiteboard:
Keywords:
: 550146 (view as bug list)
Depends on:
Blocks: 550209
  Show dependency tree
 
Reported: 2019-02-19 17:12 EST by Thomas Wolf CLA
Modified: 2019-09-08 17:13 EDT (History)
5 users (show)

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Thomas Wolf CLA 2019-02-19 17:12:08 EST
Following up on bug 544512 I did a few tests and found that EGit calls org.eclipse.jgit.util.FileUtils.lastModified() incredibly often! Now that's one of the operations that are known to be slower on a Windows file system than on typical Linux or Mac file systems. (Basically anything involving file attributes is slower on Windows.)

lastModified() is called literally hundreds of times even if only the selection changes, and a few hundred more times when a context menu in the package explorer or git repository view is to be opened. We even get these hundreds of calls when the repository the selection belongs to doesn't change.

Printing out a running count for each call of FileUtils.lastModified() quickly gets into the 10000s, all by only clicking around a little.

This is not good at all.

The problem here is that Eclipse re-evaluates many handler enablements when the selection changes. For some commands we were able to reduce this via the RepositorySourceProvider, but evidently there are still many handlers that determine the repository from the selection, and many commands then also try to determine some repository state (Which branch is checked out? Is the repo state "safe"? Is it a bare repo?) in their enablement expression or in isEnabled(). Each of these may access files on disk, and typically checks lastModified() to figure out whether state cached in Repository needs to be re-loaded or not.

Can this be changed? For a single selection change I don't want to test a few hundred times whether the packedrefs file's last-modified time (or that of some loose ref) has changed. I want to check that once, and be done with it for all the enablement calculations for this event. One way might be not to override isEnabled() in our handlers but setEnabled(Object). The Object is the evaluation context. RepositorySourceProvider could provide additional variables there for the most commonly used repo information (exactRef(HEAD), maybe getFullBranch()/getBranch(), perhaps a few frequently used others). Then our handlers could use that info from the evaluation context.

Any comments? Does anyone see a problem with this idea? Or have better ideas?
Comment 1 Thomas Wolf CLA 2019-02-20 02:10:42 EST
Also to examine: the "Switch to..." sub-menu, especially in the repositories view. Could be that this is especially intensive with these lastModified() calls. If so we'd need to figure out a way to populate that menu asynchronously. (Idea: give it initially only the fixed entries; fill in the branches from a background job. Problem: multi-repo switch may not have any fixed items.)
Comment 2 Thomas Wolf CLA 2019-02-20 03:27:42 EST
Another potentially problematic thing: property testers testing some repository property. Would need to check how often such testers are called, but I suspect each use gets evaluated separately (unless platform has some smart logic about caching the result and not re-evaluating the same tester for the same inputs, but I doubt this exists).
Comment 3 Thomas Wolf CLA 2019-02-20 05:34:58 EST
Caching more state in the RepositorySourceProvider will work only for the property testers, which probably would need to be rewritten in plugin.xml to extra variables. With careful application this may already reduce the number of times we check the last-modified time of the repo config, user config, and system config.

But a similar caching method would need to be devised for other places. We must not rely on the source provider outside of plugin.xml -- it's just a selection listener in the end, and other selection listeners may run earlier.
Comment 4 Eclipse Genie CLA 2019-02-20 06:22:14 EST
New Gerrit change created: https://git.eclipse.org/r/137271
Comment 5 Thomas Wolf CLA 2019-02-20 06:32:06 EST
(In reply to Eclipse Genie from comment #4)
> New Gerrit change created: https://git.eclipse.org/r/137271

A first little step.

My test case:

* Modify FileUtils.lastModified() to write a running count and the file path to stdout on each call.
* Start a runtime eclipse. (I'm using a 4.9 target platform for this test.)
* I have a few repos (two different test clones of egit, and the jgit repo) in the repositories view. No open editors, history closed. egit projects in the workspace, build automatically off.
* Wait until Eclipse has started and settled down. (No more output on stdout.)
* Choose two repos in the repositories view and click alternatingly click on one or the other. Don't expand nodes or context menus, just click. Do this a few times, then take note of the counts written to stdout. Keep going and write down the differences in counts.

Without this change, I get a constant 148 calls to FileUtils.lastModified().

With this change, I get a constant 108 calls.

This change actually avoids lastModified() calls done in a background job. We should probably focus on the ones that happen on the UI thread, which is likely those called via property testers or handlers' isEnabled().
Comment 6 Thomas Wolf CLA 2019-02-20 06:35:19 EST
(In reply to Thomas Wolf from comment #5)
> Without this change, I get a constant 148 calls to FileUtils.lastModified().

Sorry, 142.
Comment 7 Michael Keppler CLA 2019-02-20 09:54:47 EST
Another thing to optimize: When the selection changes, the variable "org.eclipse.egit.ui.currentRepository" is updated (search RepositorySourceProvider). That in turn leads to updating roughly 25 gitflow command enablements, which in turn each need 3 or 6 or 9... calls to lastModified (e.g. for things like isHotfix(repo.getBranch())), since they all refer to that variable.

Maybe we need just _one_ RepositorySourceChangeListener for gitflow, which calculates all those current enablement expressions as _variables_ instead (doing only one access to the config instead of 25), and then we use the variables in the command enablements.
Comment 8 Thomas Wolf CLA 2019-02-20 10:43:55 EST
(In reply to Michael Keppler from comment #7)
> Another thing to optimize: When the selection changes, the variable
> "org.eclipse.egit.ui.currentRepository" is updated (search
> RepositorySourceProvider).

It fires a change event only if the repo indeed changed. That's the whole point of this RepositorySourceProvider. So these gitflow command should be re-evaluated only when the selection changes such that the current repository changes. Which with my test is of course each time.

Yes, if we could reduce the number of times gitflow accesses the config we would have gained quite a bit already.
Comment 9 Thomas Wolf CLA 2019-02-20 16:44:54 EST
Caching more values is possible and does, as expected, reduce the number of file accesses (lastModified() in particular, will have to check exists() later). Unfortunately I see no way to do this transparently; Java code of the property testers and handlers' isEnabled() needs to be changed.

But caching more state means we need to find a way to invalidate that cache not when the selection changes, but when that repo's state changes (for instance, a branch switch or some such). Moreover, we need a way to force a re-evaluation then even if the selection didn't change. (Seems to me that might already be a problem with the current approach.) So this RepositorySourceProvider would also need to listen to ref changes and config changes on the "current repository" and then also fire a "variable changed" event.

And we have a similar problem not only with the gitflow property tester but also with the ResourcePropertyTester, which actually tests repository state of the repository the IResource belongs to. Maybe that could be made to use the same "current repository" variable in many cases.
Comment 10 Thomas Wolf CLA 2019-02-21 03:26:10 EST
Clicking around and also opening context menus (but not actually triggering any actions) and printing out the number of lastModified() calls overall and those on the UI thread shows that roughly 40-60% of these calls occur on the UI thread. Opening the context menu in the package explorer causes in my tests 126 calls on the UI thread.
Comment 11 Andrey Loskutov CLA 2019-02-21 10:20:19 EST
Just for your information, I believe we reduced number of evaluations in 4.11 Platform UI code. Not saying that the work here is meaningless, just to make you aware that measurements made on different platform versions can differ because of the platform changes.
Comment 12 Thomas Wolf CLA 2019-02-21 10:22:21 EST
(In reply to Andrey Loskutov from comment #11)
> Just for your information, I believe we reduced number of evaluations in
> 4.11 Platform UI code. Not saying that the work here is meaningless, just to
> make you aware that measurements made on different platform versions can
> differ because of the platform changes.

Oh yes. Try the above steps with the egit 4.6 target: it's even much much worse.
Comment 13 Eclipse Genie CLA 2019-02-21 10:57:08 EST
Gerrit change https://git.eclipse.org/r/137271 was merged to [master].
Commit: http://git.eclipse.org/c/egit/egit.git/commit/?id=e82658eeeee9501b5ef21c9e0e987449dc1a0792
Comment 14 Matthias Sohn CLA 2019-02-21 18:01:51 EST
In order to reduce lstat calls when reading config files in jgit we could consider to implement a config cache in JGit and use the WatchService API [1] to let the file system notify jgit about updates. I'd then just remove affected configs from the cache so that they get reloaded on the next access.

[1] https://docs.oracle.com/javase/tutorial/essential/io/notification.html
Comment 15 Thomas Wolf CLA 2019-02-22 02:31:35 EST
(In reply to Matthias Sohn from comment #14)
> In order to reduce lstat calls when reading config files in jgit we could
> consider to implement a config cache in JGit and use the WatchService API
> [1] to let the file system notify jgit about updates. I'd then just remove
> affected configs from the cache so that they get reloaded on the next access.
> 
> [1] https://docs.oracle.com/javase/tutorial/essential/io/notification.html

I had been thinking about this, too. However, such notifications are asynchronous, and thus changing the current synchronous checks must be done with care. For the config files it is certainly an option; there JGit doesn't need to know synchronously whether a config has changed (and JGit's checks doesn't account for included configs anyway).

Note the following from the WatchService javadoc:

"If a watched file is not located on a local storage device then it is implementation specific if changes to the file can be detected. In particular, it is not required that changes to files carried out on remote systems be detected."

What counts as "local storage device"? On Linux? On Windows? (I guess on Linux this is built upon inotify, so one might look there for guidance. No idea about the Windows implementation.)

So, in short: it might help reduce the number of calls for the configs, but I don't think we can use it for loose refs or other git files. Still, if it could be made to work reliably for the configs that'd be already good.

Also:

* https://bugs.openjdk.java.net/browse/JDK-6972833
* https://bugs.openjdk.java.net/browse/JDK-8162948
Comment 16 Thomas Wolf CLA 2019-08-16 07:46:36 EDT
I had done some more experiments with caching repo info (see comment 9).

The big problem with caching repo state and handler activation/enablement re-evaluations is that there is no clear life-cycle for this, and thus it's hard to tell when to invalidate a cache entry and re-load repo state.

What we'd need is something along the lines:

  1. Selection changes
  2. Platform goes update a number of things:
     2.1 Platform says "Going to update UI for new selection s"
     2.2 Platform goes re-evaluate expressions and things
     2.3 Platform says "Done updating UI for selection s"

Then we could in 2.1 cache repo state, use it during 2.2, and invalidate our cache in 2.3. Currently 2.1 and 2.3 are missing, which makes caching a hit-and-miss affair.

Or does platform have something like this?
Comment 17 Thomas Wolf CLA 2019-08-16 07:55:25 EDT
*** Bug 550146 has been marked as a duplicate of this bug. ***
Comment 18 Thomas Wolf CLA 2019-08-16 08:02:10 EDT
Note that we can't simply use a selection listener to load our cache. Platform itself triggers (2) in response to a selection change event. Order of execution of selection listeners depends on order of registration, so it essentially undefined. Our caching selection listener might thus run after the whole (2) is done. But it _must_ run after (1) and before (2.2), otherwise EGit will evaluate based on old cached state.
Comment 19 Lars Vogel CLA 2019-08-26 10:21:05 EDT
(In reply to Thomas Wolf from comment #18)
> Note that we can't simply use a selection listener to load our cache.
> Platform itself triggers (2) in response to a selection change event. Order
> of execution of selection listeners depends on order of registration, so it
> essentially undefined. Our caching selection listener might thus run after
> the whole (2) is done. But it _must_ run after (1) and before (2.2),
> otherwise EGit will evaluate based on old cached state.

AFAICS we do update the IEclipseContext with the "selection" before calling the selection listeners. See WorkbenchPage and internal class E4PartListener.

So if you listen for "selection" (ISources.ACTIVE_CURRENT_SELECTION_NAME) context changes you should be called before the selection listeners are called. I never checked in our DI implementation but AFAIK the context listeners are  synchronously updated. So you could define a model add-on which listeners to such context changes.

If that works, you should be able to be called after 1.) but before 2.) which I think you want.
Comment 20 Thomas Wolf CLA 2019-08-27 16:32:38 EDT
(In reply to Lars Vogel from comment #19)
> (In reply to Thomas Wolf from comment #18)
> > Note that we can't simply use a selection listener to load our cache.
> > Platform itself triggers (2) in response to a selection change event. Order
> > of execution of selection listeners depends on order of registration, so it
> > essentially undefined. Our caching selection listener might thus run after
> > the whole (2) is done. But it _must_ run after (1) and before (2.2),
> > otherwise EGit will evaluate based on old cached state.
> 
> AFAICS we do update the IEclipseContext with the "selection" before calling
> the selection listeners. See WorkbenchPage and internal class E4PartListener.
> 
> So if you listen for "selection" (ISources.ACTIVE_CURRENT_SELECTION_NAME)
> context changes you should be called before the selection listeners are
> called. I never checked in our DI implementation but AFAIK the context
> listeners are  synchronously updated. So you could define a model add-on
> which listeners to such context changes.
> 
> If that works, you should be able to be called after 1.) but before 2.)
> which I think you want.

What exactly did you have in mind? Somehow get the IEclipseContext of the window and add a RunAndTrack that accesses the selection item? But RATs are guaranteed to be executed synchronously, and other computations may run earlier as far as I see. Or did you mean something else?
Comment 21 Thomas Wolf CLA 2019-08-27 16:33:19 EDT
(In reply to Thomas Wolf from comment #20)
> But RATs are

**not**

> guaranteed to be executed synchronously, and other computations may run
> earlier as far as I see. Or did you mean something else?
Comment 22 Lars Vogel CLA 2019-08-27 17:12:50 EDT
(In reply to Thomas Wolf from comment #21)
> (In reply to Thomas Wolf from comment #20)
> > But RATs are
> 
> **not**
> 
> > guaranteed to be executed synchronously, and other computations may run
> > earlier as far as I see. Or did you mean something else?

I had a model add-on in mind, see https://www.vogella.com/tutorials/Eclipse4ModelEvents/article.html#add-a-new-model-add-on
Comment 23 Eclipse Genie CLA 2019-08-30 15:59:56 EDT
New Gerrit change created: https://git.eclipse.org/r/148656
Comment 24 Thomas Wolf CLA 2019-08-31 13:31:55 EDT
CommitGraphTable.doPaint() also causes lots of file accesses since it repeatedly calls input.getHead(). I wonder if we can cache that...
Comment 25 Eclipse Genie CLA 2019-09-01 07:20:09 EDT
New Gerrit change created: https://git.eclipse.org/r/148671