On some repos, clever deploy is very slow (under the hood isogit push)

hsablonniere commented 5 years ago

We're investigating this...

To be clear, this issue concerns problems with the push done by isomorphic-git when calling clever deploy. If a deploy displays some logs and nevers ends, you maybe look at #319 (or #318).

hsablonniere commented 5 years ago

$ git sizer --verbose
Processing blobs: 6116
Processing trees: 9337
Processing commits: 1516
Matching commits to trees: 1516
Processing annotated tags: 0
Processing references: 114
| Name                         | Value     | Level of concern               |
| ---------------------------- | --------- | ------------------------------ |
| Overall repository size      |           |                                |
| * Commits                    |           |                                |
|   * Count                    |  1.52 k   |                                |
|   * Total size               |   552 KiB |                                |
| * Trees                      |           |                                |
|   * Count                    |  9.34 k   |                                |
|   * Total size               |  4.79 MiB |                                |
|   * Total tree entries       |   122 k   |                                |
| * Blobs                      |           |                                |
|   * Count                    |  6.12 k   |                                |
|   * Total size               |   189 MiB |                                |
| * Annotated tags             |           |                                |
|   * Count                    |     0     |                                |
| * References                 |           |                                |
|   * Count                    |   114     |                                |
|                              |           |                                |
| Biggest objects              |           |                                |
| * Commits                    |           |                                |
|   * Maximum size         [1] |  1.52 KiB |                                |
|   * Maximum parents      [2] |     2     |                                |
| * Trees                      |           |                                |
|   * Maximum entries      [3] |   144     |                                |
| * Blobs                      |           |                                |
|   * Maximum size         [4] |  57.5 MiB | ******                         |
|                              |           |                                |
| History structure            |           |                                |
| * Maximum history depth      |  1.28 k   |                                |
| * Maximum tag depth          |     0     |                                |
|                              |           |                                |
| Biggest checkouts            |           |                                |
| * Number of directories  [5] |   140     |                                |
| * Maximum path depth     [5] |     7     |                                |
| * Maximum path length    [5] |    92 B   |                                |
| * Number of files        [5] |   957     |                                |
| * Total size of files    [6] |   116 MiB |                                |
| * Number of symlinks         |     0     |                                |
| * Number of submodules       |     0     |                                |

justfortherec commented 4 years ago

Is there any new information on this?

We see the same symptoms (clever deploy not terminating) and have similar Git repositories with maximum blob size up to 55MB. In the logs I see the following success message but the clever-tool keeps being attached to the logs.

Successfully deployed in 2 minutes and 14 seconds

This breaks our CI flow because the command never returns and the task times out.

Is there a workaround we could apply?

Edit: These are git sizer outputs of two (local clones of) repositories where we see this happening:

> git sizer --verbose
Processing blobs: 82
Processing trees: 88
Processing commits: 139
Matching commits to trees: 139
Processing annotated tags: 0
Processing references: 22
| Name                         | Value     | Level of concern               |
| ---------------------------- | --------- | ------------------------------ |
| Overall repository size      |           |                                |
| * Commits                    |           |                                |
|   * Count                    |   139     |                                |
|   * Total size               |  45.1 KiB |                                |
| * Trees                      |           |                                |
|   * Count                    |    88     |                                |
|   * Total size               |  11.0 KiB |                                |
|   * Total tree entries       |   277     |                                |
| * Blobs                      |           |                                |
|   * Count                    |    82     |                                |
|   * Total size               |  1.74 GiB |                                |
| * Annotated tags             |           |                                |
|   * Count                    |     0     |                                |
| * References                 |           |                                |
|   * Count                    |    22     |                                |
|                              |           |                                |
| Biggest objects              |           |                                |
| * Commits                    |           |                                |
|   * Maximum size         [1] |   448 B   |                                |
|   * Maximum parents      [2] |     2     |                                |
| * Trees                      |           |                                |
|   * Maximum entries      [3] |     6     |                                |
| * Blobs                      |           |                                |
|   * Maximum size         [4] |  48.0 MiB | *****                          |
|                              |           |                                |
| History structure            |           |                                |
| * Maximum history depth      |    68     |                                |
| * Maximum tag depth          |     0     |                                |
|                              |           |                                |
| Biggest checkouts            |           |                                |
| * Number of directories  [3] |     2     |                                |
| * Maximum path depth     [3] |     2     |                                |
| * Maximum path length    [5] |    41 B   |                                |
| * Number of files        [6] |     6     |                                |
| * Total size of files    [6] |  89.3 MiB |                                |
| * Number of symlinks     [3] |     1     |                                |
| * Number of submodules       |     0     |                                |

> git sizer --verbose
Processing blobs: 57
Processing trees: 55
Processing commits: 71
Matching commits to trees: 71
Processing annotated tags: 0
Processing references: 24
| Name                         | Value     | Level of concern               |
| ---------------------------- | --------- | ------------------------------ |
| Overall repository size      |           |                                |
| * Commits                    |           |                                |
|   * Count                    |    71     |                                |
|   * Total size               |  23.0 KiB |                                |
| * Trees                      |           |                                |
|   * Count                    |    55     |                                |
|   * Total size               |  8.66 KiB |                                |
|   * Total tree entries       |   219     |                                |
| * Blobs                      |           |                                |
|   * Count                    |    57     |                                |
|   * Total size               |   972 MiB |                                |
| * Annotated tags             |           |                                |
|   * Count                    |     0     |                                |
| * References                 |           |                                |
|   * Count                    |    24     |                                |
|                              |           |                                |
| Biggest objects              |           |                                |
| * Commits                    |           |                                |
|   * Maximum size         [1] |   874 B   |                                |
|   * Maximum parents      [2] |     2     |                                |
| * Trees                      |           |                                |
|   * Maximum entries      [3] |     6     |                                |
| * Blobs                      |           |                                |
|   * Maximum size         [4] |  55.2 MiB | *****                          |
|                              |           |                                |
| History structure            |           |                                |
| * Maximum history depth      |    40     |                                |
| * Maximum tag depth          |     0     |                                |
|                              |           |                                |
| Biggest checkouts            |           |                                |
| * Number of directories  [3] |     2     |                                |
| * Maximum path depth     [3] |     2     |                                |
| * Maximum path length    [3] |    26 B   |                                |
| * Number of files        [3] |     5     |                                |
| * Total size of files    [3] |  55.2 MiB |                                |
| * Number of symlinks     [3] |     1     |                                |
| * Number of submodules       |     0     |                                |

justfortherec commented 4 years ago

For the time being we will fall back to use git push instead of clever deploy. I'd still be happy to be able to use clever-tools again.

hsablonniere commented 4 years ago

@justfortherec Hey, thanks for you report ;-)

This issue only concerns the git push that is done under the hood by our CLI. Did you see this line?

Your source code has been pushed to Clever Cloud.

If you see this, the problem does not come from the git push but from the way we handle logs and events which is discussed here: https://github.com/CleverCloud/clever-tools/issues/318 and https://github.com/CleverCloud/clever-tools/issues/319

justfortherec commented 4 years ago

Yes, you are right. The problem on my side is not the deployment. It works on Clever Cloud. Only my CI task times out because clever-tool never returns.

Sorry if I misunderstood this issue here. It seems to describe the symptoms that I see ("and sometimes never ends"). I will continue discussion on the linked bugs. Thanks for pointing that out.

hsablonniere commented 4 years ago

Sorry if I misunderstood this issue here. It seems to describe the symptoms that I see ("and sometimes never ends"). I will continue discussion on the linked bugs. Thanks for pointing that out.

Don't worry, the bugs are on our side ;-)

jygastaud commented 4 years ago

Any update on that bug ? We have that issue and I make our CI failed / timeout.

We have 2 different "flavors" of the bug:

Sometimes we have logs but the command not exit after "success"
Sometimes we just see the message that the code is pushed. Deployment happen well in CC but we never have log nor exit the job.

That issue is a blocker for our process as we have other tasks that should be run after the deployment.

hsablonniere commented 4 years ago

@jygastaud We're considering patching this in the CLI while we wait for a better fix on the backend problem...

hsablonniere commented 4 years ago

@jygastaud FYI, I made the mistake (once again) of talking about the "build never ends because of events/logs" problem in this thread while it should be discussed in #319 and #318.

This thread is about problems with the inner usage of isomorphic-git push of clever deploy. We worked on this recently and we made progress, see #392 for more details...

EmrysMyrddin commented 4 years ago

I'm facing the same issue here. Pushing with git ends instantly, but clever deploy takes a lot of time to push the code (before Your source code has been pushed to Clever Cloud. message appears).

It some times even not end at all (or it's to long to wait for it ^^).

Tell me if you want more informations or logs.

Here is the result of git sizer :

➜ git sizer --verbose
Processing blobs: 18359                        
Processing trees: 32908                        
Processing commits: 3484                        
Matching commits to trees: 3484                        
Processing annotated tags: 0                        
Processing references: 605                        
| Name                         | Value     | Level of concern               |
| ---------------------------- | --------- | ------------------------------ |
| Overall repository size      |           |                                |
| * Commits                    |           |                                |
|   * Count                    |  3.48 k   |                                |
|   * Total size               |  1.96 MiB |                                |
| * Trees                      |           |                                |
|   * Count                    |  32.9 k   |                                |
|   * Total size               |  11.0 MiB |                                |
|   * Total tree entries       |   306 k   |                                |
| * Blobs                      |           |                                |
|   * Count                    |  18.4 k   |                                |
|   * Total size               |   286 MiB |                                |
| * Annotated tags             |           |                                |
|   * Count                    |     0     |                                |
| * References                 |           |                                |
|   * Count                    |   605     |                                |
|                              |           |                                |
| Biggest objects              |           |                                |
| * Commits                    |           |                                |
|   * Maximum size         [1] |  3.28 KiB |                                |
|   * Maximum parents      [2] |     3     |                                |
| * Trees                      |           |                                |
|   * Maximum entries      [3] |    48     |                                |
| * Blobs                      |           |                                |
|   * Maximum size         [4] |  1.36 MiB |                                |
|                              |           |                                |
| History structure            |           |                                |
| * Maximum history depth      |  1.88 k   |                                |
| * Maximum tag depth          |     0     |                                |
|                              |           |                                |
| Biggest checkouts            |           |                                |
| * Number of directories  [5] |   561     |                                |
| * Maximum path depth     [6] |    11     | *                              |
| * Maximum path length    [7] |   127 B   | *                              |
| * Number of files        [5] |  2.17 k   |                                |
| * Total size of files    [8] |  6.30 MiB |                                |
| * Number of symlinks     [9] |     1     |                                |
| * Number of submodules       |     0     |                                |

[1]  e3968c6ce8c6f95cae4412d8110141d728a485a5
[2]  28efba4692d93b4c57072e17c470fbd9ec1ba615 (refs/stash)
[3]  9e3d411a7d70afca778ed1ded785bb0d044b1b1d (refs/heads/louche:graph/src/fetchers/repositories/pathways-import/data)
[4]  3c46f715a9ca41732ca8c64a145fa1d05da5deb5 (refs/heads/test/mono-db:app/students/src/components/let-it-go/let-it-go.gif)
[5]  9f13f6dbf5ea539a0bbe5d753a38b7fdce284e84 (830a2e8e2037420403224e0846428de0873c14b1^{tree})
[6]  a5b3194b169e35c47b87d145b876af1af2dc58f8 (refs/heads/test/mono-db^{tree})
[7]  2647bfe618077506f8b8884f690b80b84a889c32 (ce4e109783211b2fa428eadf0c50c78ac7400631^{tree})
[8]  48bc2839278d8c52ee5d4fa51862051483d78fa5 (0bb44127c29712dfc6753d386e507207d91305bc^{tree})
[9]  5fe512e8ecced56a60dc474fdac7b65cec077929 (1e02bcdd828272d03b573fb472e1466dd4773165:api/common)

hsablonniere commented 4 years ago

Hello @EmrysMyrddin and others facing this issue.

I should have written an update sooner. Sorry.

TL;DR:

These oid and slow problems seems to come from isomorphic-git
The 4 issues we created one isomorphic-git in May have been fixed a few weeks ago
We should be able to update and test this week

Thanks for you patience...

EmrysMyrddin commented 4 years ago

Ok nice, thank you for the update :-)

If you need some tester for this, I'm here to help.

hsablonniere commented 4 years ago

@justfortherec @jygastaud @EmrysMyrddin and others

I updated to latest 1.7.0 of isomorphic-git and started some tests:

On the repo of the Clever Cloud console:

git-sizer --verbose (edited)

| Name                         | Value     | Level of concern               |
| ---------------------------- | --------- | ------------------------------ |
| Overall repository size      |           |                                |
| * Commits                    |           |                                |
|   * Count                    |  3.46 k   |                                |
|   * Total size               |  1.38 MiB |                                |
| * Trees                      |           |                                |
|   * Count                    |  14.9 k   |                                |
|   * Total size               |  11.4 MiB |                                |
|   * Total tree entries       |   267 k   |                                |
| * Blobs                      |           |                                |
|   * Count                    |  8.13 k   |                                |
|   * Total size               |  69.6 MiB |                                |
| Biggest objects              |           |                                |
| * Commits                    |           |                                |
|   * Maximum size         [1] |  1.31 KiB |                                |
|   * Maximum parents      [2] |     2     |                                |
| * Trees                      |           |                                |
|   * Maximum entries      [3] |   119     |                                |
| * Blobs                      |           |                                |
|   * Maximum size         [4] |   443 KiB |                                |
| History structure            |           |                                |
| * Maximum history depth      |  2.86 k   |                                |
| Biggest checkouts            |           |                                |
| * Number of directories  [5] |   117     |                                |
| * Number of files        [7] |   606     |                                |
| * Total size of files    [8] |  4.82 MiB |                                |
| * Number of submodules       |     0     |                                |

Here's how much time is spent by git.push in a clever deploy in various situations (with old and new version of isogit):

Brand new app, empty repo
- 1.7.0: 33s
- 0.37.0: 86s
console push just one new commit
- 1.7.0: 2.8s
- 0.37.0: 3s
console force-push one commit
- 1.7.0: 500ms
- 0.37.0: 58s

We're really satisfied with those improvements.

hsablonniere commented 4 years ago

We're facing a new problem now on a repo that has a submodule. It won't push anymore, we get a read error on the object commit of the submodule.

hsablonniere commented 4 years ago

OK, we may have found a bug fix for the submodule problem.

Let's try a beta release without this bugfix for now to test if it works on repo without submodules.

hsablonniere commented 4 years ago

@justfortherec @jygastaud @EmrysMyrddin @anthonny @raphaelbauduin and others, can you try this new 2.6.2-beta.0 version?

https://github.com/CleverCloud/clever-tools/releases/tag/2.6.2-beta.0

EmrysMyrddin commented 4 years ago

I can confirm it seems a lot faster. Still significantly slower than normal git push -f but it's acceptable I think.

git push -f clever master:test is less than 1 second clever deploy -f -b test "pushing code" step is a little more than 3 seconds.

hsablonniere commented 4 years ago

@EmrysMyrddin Yes, it's still slower than a git push, sorry for this. Did you have the oid read error before? Does it fix the problem?

EmrysMyrddin commented 4 years ago

I never had this error sorry.

hsablonniere commented 4 years ago

OK, update:

this isogit update helped us to identify users with a shallow repo (see #293)
we have one confirm case where a read oid pb disappeared with this beta
we have one weird behaviour that I can't reproduce with @anthonny

hsablonniere commented 4 years ago

@dsferruzza I seem to remember you had this problem at some point?

hsablonniere commented 4 years ago

OK, submodule regression was fixed :tada: https://github.com/isomorphic-git/isomorphic-git/issues/1185#issuecomment-659712026

You can expect a stable release in the next few days.

dsferruzza commented 4 years ago

@dsferruzza I seem to remember you had this problem at some point?

I just had the opportunity to run clever deploy -f (using 2.6.2-beta.1) today with my "big" repo from a place where the upload speed is not fast and it was quite slow 😶. I forgot to run a timer but it took something like ~20-30 minutes before pushing source code; feels like before.

This is not a blocker for me and I'll do my best to keep monitoring this, especially if you release new versions!

hsablonniere commented 4 years ago

@dsferruzza Grrr, the 2.6.2-beta.1 is supposed to be faster but not for clean repo I guess.

hsablonniere commented 4 years ago

Released in https://github.com/CleverCloud/clever-tools/releases/tag/2.7.0 https://github.com/CleverCloud/clever-tools/blob/master/CHANGELOG.md#270-2020-08-20

CleverCloud / clever-tools

On some repos, clever deploy is very slow (under the hood isogit push) #354