Bug 580310 - Delta resolution after clone takes over 1h
Summary: Delta resolution after clone takes over 1h
Status: NEW
Alias: None
Product: JGit
Classification: Technology
Component: JGit (show other bugs)
Version: 5.13   Edit
Hardware: PC Mac OS X
: P3 normal (vote)
Target Milestone: ---   Edit
Assignee: Project Inbox CLA
QA Contact:
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2022-06-30 08:17 EDT by Luca Milanesio CLA
Modified: 2023-07-16 03:09 EDT (History)
5 users (show)

See Also:


Attachments
method profiling (774.99 KB, image/png)
2022-06-30 18:51 EDT, Matthias Sohn CLA
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Luca Milanesio CLA 2022-06-30 08:17:21 EDT
I have created a test repository with 240k refs and 720k objects, with 240k deltas (every commit is modifying the same file).

See below the script used:
for ((i=0; i<245760; i++ ))
do
  echo foo$i >> foo
  jgit add foo
  jgit  commit -m foo$i
  jgit checkout -b branch-$(expr $i '/' 100)/part-$(expr $i '%' 100)
done

After the repo creation, it has been fully GCed and bitmaps created, so that there is a single packfile, index and bitmap.
All refs are a single packed-refs file.

The clone with Git takes 2 mins and 57s:
 time git clone http://localhost:8080/load-test-1
Cloning into 'load-test-1'...
remote: Counting objects: 16563, done
remote: Finding sources: 100% (726619/726619)
remote: Total 726619 (delta 242147), reused 726615 (delta 242147)
Receiving objects: 100% (726619/726619), 94.22 MiB | 31.16 MiB/s, done.
Resolving deltas: 100% (242147/242147), done.
git clone http://localhost:8080/load-test-1  1134.36s user 98.73s system 696% cpu 2:57.12 total

The clone with JGit takes 1h and 3mins:
 time ./jgit clone http://localhost:8080/load-test-1
Cloning into 'load-test-1'...
remote: Counting objects: 1
remote: Finding sources: 100% (726619/726619)
Receiving objects:      100% (726619/726619)
Resolving deltas:       100% (242147/242147)
Checking out files:     100% (1/1)

jgit clone http://localhost:8080/load-test-1  4974.86s user 53.23s system 132% cpu 1:03:20.57 total

I have already applied all the improvements on top of the latest stable-5.13:
- https://git.eclipse.org/r/c/jgit/jgit/+/193464
- https://git.eclipse.org/r/c/jgit/jgit/+/194140

From what I see, the majority of the time is spent in the deltas resolution, which I know is huge in this case because all commits are appending to the same file.

However, why JGit is 20x times slower than C-Git?
Comment 1 Matthias Sohn CLA 2022-06-30 18:50:22 EDT
looks like it spends most time in methods of org.eclipse.jgit.util.sha1.SHA1 which was introduced in 982f5d1bf184a2edab726f3c77f09a1157059e35 and replaced MessageDigest in 0f25f64d4882f7853c9d3dc84ec382d8a78ae646
Comment 2 Matthias Sohn CLA 2022-06-30 18:51:58 EDT
Created attachment 288612 [details]
method profiling

screenshot of method profiling done with Java Mission Control/Flight Recorder
Comment 3 Matthias Sohn CLA 2022-06-30 18:57:45 EDT
On my Mac jgit on Java 11 took 1756 seconds vs git taking 131 seconds, that means it was 13.4 times slower.
Comment 4 Andrey Loskutov CLA 2022-07-01 12:25:03 EDT
(In reply to Matthias Sohn from comment #1)
> looks like it spends most time in methods of org.eclipse.jgit.util.sha1.SHA1
> which was introduced in 982f5d1bf184a2edab726f3c77f09a1157059e35 and
> replaced MessageDigest in 0f25f64d4882f7853c9d3dc84ec382d8a78ae646

I can't find those commits above, did you mean c90ab1a77430562cb543d0177fd94cf67ef97bcf?

@Jonathan, I'm just curious: I don't see any comments *why* jgit switched from MessageDigest in JDK to own "pure Java SHA1" implementation? What was wrong with the one from JDK?
Comment 5 David Ostrovsky CLA 2022-07-01 16:02:22 EDT
(In reply to Andrey Loskutov from comment #4)
> (In reply to Matthias Sohn from comment #1)
> > looks like it spends most time in methods of org.eclipse.jgit.util.sha1.SHA1
> > which was introduced in 982f5d1bf184a2edab726f3c77f09a1157059e35 and
> > replaced MessageDigest in 0f25f64d4882f7853c9d3dc84ec382d8a78ae646
> 
> I can't find those commits above, did you mean
> c90ab1a77430562cb543d0177fd94cf67ef97bcf?

See: [1].

[1] https://git.eclipse.org/r/c/jgit/jgit/+/91837

> @Jonathan, I'm just curious: I don't see any comments *why* jgit switched
> from MessageDigest in JDK to own "pure Java SHA1" implementation? What was
> wrong with the one from JDK?

See commit message in: [1].
Comment 6 Luca Milanesio CLA 2022-07-01 17:29:41 EDT
Thanks @Matthias and @Davido for the analysis, very interesting finding.

I was wondering if the SHA1 implemented by Shawn could fallback to MessageDigest if org.eclipse.jgit.util.sha1.detectCollision is set to false.

At the end of the day, if we don't detect the SHA1 collisions, then the pure-Java implementation isn't going to have substantial benefits against the one in MessageDigest of the JDK, isn't it?

WDYT?
Comment 7 David Ostrovsky CLA 2022-07-02 03:24:34 EDT
(In reply to Luca Milanesio from comment #6)
> Thanks @Matthias and @Davido for the analysis, very interesting finding.
> 
> I was wondering if the SHA1 implemented by Shawn could fallback to
> MessageDigest if org.eclipse.jgit.util.sha1.detectCollision is set to false.
> 
> At the end of the day, if we don't detect the SHA1 collisions, then the
> pure-Java implementation isn't going to have substantial benefits against
> the one in MessageDigest of the JDK, isn't it?

I tend to agree. But could you try to re-run your test with:

  -Dorg.eclipse.jgit.util.sha1.detectCollision=false

With collision detection disabled, the method `UbcCheck#check(int[] w)`
shouldn't be called any more, so that you should already see significant
performance improvement, right?
Comment 8 Luca Milanesio CLA 2022-07-02 16:06:02 EDT
(In reply to David Ostrovsky from comment #7)
> (In reply to Luca Milanesio from comment #6)
> > Thanks @Matthias and @Davido for the analysis, very interesting finding.
> > 
> > I was wondering if the SHA1 implemented by Shawn could fallback to
> > MessageDigest if org.eclipse.jgit.util.sha1.detectCollision is set to false.
> > 
> > At the end of the day, if we don't detect the SHA1 collisions, then the
> > pure-Java implementation isn't going to have substantial benefits against
> > the one in MessageDigest of the JDK, isn't it?
> 
> I tend to agree. But could you try to re-run your test with:
> 
>   -Dorg.eclipse.jgit.util.sha1.detectCollision=false
> 
> With collision detection disabled, the method `UbcCheck#check(int[] w)`
> shouldn't be called any more, so that you should already see significant
> performance improvement, right?

I'm running it with detectCollision disabled, however, the improvement is pretty minor.
Comment 9 Luca Milanesio CLA 2022-07-02 17:09:41 EDT
(In reply to Luca Milanesio from comment #8)
> (In reply to David Ostrovsky from comment #7)
> > (In reply to Luca Milanesio from comment #6)
> > > Thanks @Matthias and @Davido for the analysis, very interesting finding.
> > > 
> > > I was wondering if the SHA1 implemented by Shawn could fallback to
> > > MessageDigest if org.eclipse.jgit.util.sha1.detectCollision is set to false.
> > > 
> > > At the end of the day, if we don't detect the SHA1 collisions, then the
> > > pure-Java implementation isn't going to have substantial benefits against
> > > the one in MessageDigest of the JDK, isn't it?
> > 
> > I tend to agree. But could you try to re-run your test with:
> > 
> >   -Dorg.eclipse.jgit.util.sha1.detectCollision=false
> > 
> > With collision detection disabled, the method `UbcCheck#check(int[] w)`
> > shouldn't be called any more, so that you should already see significant
> > performance improvement, right?
> 
> I'm running it with detectCollision disabled, however, the improvement is
> pretty minor.

Cloning into 'load-test-1-no-cd'...
remote: Counting objects: 1
remote: Finding sources: 100% (726619/726619)
remote: Getting sizes:  100% (242270/242270)
remote: Compressing objects: 100% (4897/4897)
Receiving objects:      100% (726619/726619)
Resolving deltas:       100% (242150/242150)
Checking out files:     100% (1/1)

./jgit clone /tmp/gerrit_setup/instance-1/git/load-test-1.git   3675.27s user 54.14s system 126% cpu 49:01.23 total

63 - 49 = 14 mins (22% of improvement by disabling collision detection)
Comment 10 David Ostrovsky CLA 2022-11-15 05:21:41 EST
> > I'm running it with detectCollision disabled, however, the improvement is
> > pretty minor.
> 
> Cloning into 'load-test-1-no-cd'...
> remote: Counting objects: 1
> remote: Finding sources: 100% (726619/726619)
> remote: Getting sizes:  100% (242270/242270)
> remote: Compressing objects: 100% (4897/4897)
> Receiving objects:      100% (726619/726619)
> Resolving deltas:       100% (242150/242150)
> Checking out files:     100% (1/1)
> 
> ./jgit clone /tmp/gerrit_setup/instance-1/git/load-test-1.git   3675.27s
> user 54.14s system 126% cpu 49:01.23 total
> 
> 63 - 49 = 14 mins (22% of improvement by disabling collision detection)

Can you re-run the tests with this change: [1], and set the property to use JDK native message digest implementation?

Also note, that SHA1 benchmark was added here: [2].

[1] https://git.eclipse.org/r/c/jgit/jgit/+/196905
[2] https://git.eclipse.org/r/c/jgit/jgit/+/196906
Comment 11 Luca Milanesio CLA 2022-11-15 09:11:54 EST
I'll re-run with the native MessageDigest implemented in [1].

Also, the SHA1 was responsible for a high execution time when checking if a packedrefs file was changed on the filesystem (when trustFolderStat = false, JGit computes the SHA1s and compares them)

Luca.
Comment 14 Andrey Loskutov CLA 2022-12-21 14:31:23 EST
Coming here back from release notes, https://projects.eclipse.org/projects/technology.jgit/releases/6.4.0 where this bug is mentioned as fixed and that there is a new option available. 

However the bug is still open (mistake or missing something?) and as user I don't see which option/API is supposed to be used now?
Comment 15 Luca Milanesio CLA 2023-01-16 16:51:20 EST
After the merge of [1], according to Matthias, there is a 27% improvement, which is good, but still, very far away from the C-Git performance.

I believe there could be something more going on. I'd suggest to keep this bug open for now.

[1] https://git.eclipse.org/r/c/jgit/jgit/+/196906
Comment 16 Eclipse Genie CLA 2023-02-01 08:33:53 EST
New Gerrit change created: https://git.eclipse.org/r/c/jgit/jgit/+/199711
Comment 17 Matthias Sohn CLA 2023-02-01 08:34:35 EST
(In reply to Andrey Loskutov from comment #14)
> Coming here back from release notes,
> https://projects.eclipse.org/projects/technology.jgit/releases/6.4.0 where
> this bug is mentioned as fixed and that there is a new option available. 
> 
> However the bug is still open (mistake or missing something?) and as user I
> don't see which option/API is supposed to be used now?

The new option is core.sha1implementation, it can be set to "java" (Java implementation) or "jdkNative" (native implementation available in JDK).

You can also set this via system property "org.eclipse.jgit.util.sha1.implementation". If both are set the system property takes precedence.

Sorry for missing to document this, please review https://git.eclipse.org/r/c/jgit/jgit/+/199711
Comment 19 Jörg Kubitz CLA 2023-07-16 03:09:06 EDT
I also saw hotspot in SHA1Java - and it's kinda frustrating that network is faster then CPU. 
An improvement could be to utilize more threads. SHA1 computation can probably not parallelized well but distinct SHA1 computations could run in parallel.
For example the loop in PackParser.java:534

Stacktrace:

void org.eclipse.jgit.util.sha1.SHA1Java.compress() (SHA1Java.java:258)
void org.eclipse.jgit.util.sha1.SHA1Java.compress(byte[], int) (SHA1Java.java:163)
void org.eclipse.jgit.util.sha1.SHA1Java.update(byte[], int, int)(SHA1Java.java:151)
void org.eclipse.jgit.transport.PackParser.whole(long, int, long)  (PackParser.java:1064)
void org.eclipse.jgit.transport.PackParser.indexOneObject() (PackParser.java:983)
PackLock org.eclipse.jgit.transport.PackParser.parse(ProgressMonitor, ProgressMonitor) (PackParser.java:534)
PackLock org.eclipse.jgit.internal.storage.file.ObjectDirectoryPackParser.parse(ProgressMonitor, ProgressMonitor) (ObjectDirectoryPackParser.java:170)
PackLock org.eclipse.jgit.transport.PackParser.parse(ProgressMonitor) (PackParser.java:495)
void org.eclipse.jgit.transport.BasePackFetchConnection.receivePack(ProgressMonitor, OutputStream) (BasePackFetchConnection.java:1115)
void org.eclipse.jgit.transport.BasePackFetchConnection.doFetchV2(ProgressMonitor, Collection, OutputStream):545
void org.eclipse.jgit.transport.BasePackFetchConnection.doFetch(ProgressMonitor, Collection, Set, OutputStream):425
void org.eclipse.jgit.transport.TransportHttp$SmartHttpFetchConnection.doFetch(ProgressMonitor, Collection, Set, OutputStream):1562
void org.eclipse.jgit.transport.BasePackFetchConnection.fetch(ProgressMonitor, Collection, Set, OutputStream):351
void org.eclipse.jgit.transport.BasePackFetchConnection.fetch(ProgressMonitor, Collection, Set):342
void org.eclipse.jgit.transport.FetchProcess.fetchObjects(ProgressMonitor):290
void org.eclipse.jgit.transport.FetchProcess.executeImp(ProgressMonitor, FetchResult, String):182
void org.eclipse.jgit.transport.FetchProcess.execute(ProgressMonitor, FetchResult, String):105
FetchResult org.eclipse.jgit.transport.Transport.fetch(ProgressMonitor, Collection, String):1462
FetchResult org.eclipse.jgit.api.FetchCommand.call():238
FetchResult org.eclipse.jgit.api.CloneCommand.fetch(Repository, URIish):325
Git org.eclipse.jgit.api.CloneCommand.call():191