Fix perf regression #6204

arcanis · 2018-08-01T19:35:46Z

Summary

Fixes #6177

This diff fixes the perf regression introduced by #6010. New logic:

Instead of comparing the files content, we go back to checking the mtime
Since we cannot rely on npm to provide the timestamp, we set it when we fetch the files
Since the user caches have already been "corrupted" with wrong timestamps, we need to bump it
This has the unfortunate side effects that we lose the ability to avoid copying files that didn't change between two different releases (for example if x.y.1 changes a single file, we will still need to copy each file it contains). This is because we don't get the individual file timestamps from npm.

Notes:

Some hack is needed in order to workaround utimes doesn't seem to support subseconds times nodejs/node#22070 - specifically, we need to use futimes instead of utimes when unpacking the files (otherwise we lose the subsecond precision).
Instead of bumping the cache, we could special case the 23 Oct 1985. That seems fragile, though.

Test plan

Added a test.

…equality (yarnpkg#6010)" This reverts commit c53d039.

buildsize · 2018-08-01T19:40:37Z

File name	Previous Size	New Size	Change
yarn-[version].noarch.rpm	919.97 KB	920.15 KB	177 bytes (0%)
yarn-[version].js	4.02 MB	4.02 MB	737 bytes (0%)
yarn-legacy-[version].js	4.18 MB	4.18 MB	1018 bytes (0%)
yarn-v[version].tar.gz	925.55 KB	925.8 KB	264 bytes (0%)
yarn_[version]all.deb	675.07 KB	675.27 KB	202 bytes (0%)

BYK

Idea is sound but I'm concerned about the "patched fs" thing and failing tests

BYK · 2018-08-01T20:00:18Z

src/fetchers/tarball-fetcher.js

@@ -93,12 +93,39 @@ export default class TarballFetcher extends BaseFetcher {
  } {
    const integrityInfo = this._supportedIntegrity();

+    const now = new Date();


Move this closer to where it is used?

No, it's here because I don't want each file of a single package to have a different timestamp (like it would be the case if the Date constructor was called inside the closure where it is used).

BYK · 2018-08-01T20:01:18Z

src/fetchers/tarball-fetcher.js

+    const now = new Date();
+
+    const fs = require('fs');
+    const patchedFs = Object.assign({}, fs, {


Ugh, why are we patching fs where we already have our own fs functions module?

Because it's not the same. The tar-fs package is doing utimes call in order to set the files timestamps. This function is broken and doesn't support subsecond timestamps. The only way to solve this without forking tar-fs is to give it an api-compatible version of the fs module, patched in order to use futimes instead of utimes.

Ideally the fix should be done upstream, but this issue is problematic enough that it warrants an hotfix to land faster.

Is it possible to monkey patch tar-fs rather than fs? That seems like a better idea to me.

No, utimes is used within a closure. I also prefer to patch a function with clearly defined (if a bit buggy) inputs/output rather than a random function from a module that can change without notice.

Also note that this code doesn't modify the global fs implementation. It simply creates a new, local, fs instance and pass it to tar-fs using its custom filesystem option, which seems perfect for this use case.

I agree this is a good solution in regards to tar-fs. It does kind of bloat the file a little. Do you think it'll be possible to move untar-stream outside somehow?

Hm maybe it could be moved in src/utils/fs, yeah 👍

arcanis · 2018-08-01T20:40:07Z

I'll check this tomorrow, but I have a high confidence the tests are failing only because of the bumped cache version (which changes the cache path from /v1/ to /v2/). Plus linting, obviously.

acao · 2018-08-02T18:51:49Z

@arcanis looks like it failed on an async timeout, maybe try to re-run? not familiar with this suite.

arcanis · 2018-08-02T19:22:37Z

Yeah this is a known flaky test, I'll merge the PR as soon as a contributor reviews the PR (cc @BYK / @imsnif ?)

arcanis · 2018-08-03T09:21:14Z

Given the lack of explicit ack, since the tests pass and the fix has been confirmed to work, I'll assume that no explicit "Request Change" review is a go. Any change will be in a followup.

imsnif

Sorry it took me some time to get to this - I think I missed the merge by just a few minutes. :)
In any case, as @arcanis mentions - these can be addressed in subsequent PRs.

imsnif · 2018-08-03T09:04:08Z

__tests__/commands/install/integration.js

@@ -111,6 +112,20 @@ test('installing a package with a renamed file should not delete it', () =>
    expect(await fs.exists(`${config.cwd}/node_modules/pkg/state.js`)).toEqual(true);
  }));

+test("installing a new package should correctly update it, even if the files mtime didn't change", () =>
+  runInstall({}, 'mtime-same', async (config, reporter): Promise<void> => {
+    await misc.sleep(2000);


Any chance we can do this manually somehow rather than prolonging the test?

I'm afraid not - even with the subsecond fs patch, subsecond timings still won't work on filesystems that don't support it at all (I think it might be the case on CircleCI), so we need to wait at least >1s to be sure that the mtime will change.

Another option might be to mock the fs module here, but it seemed a bit hazardous so I went with the sleep (since the tests are executed in parallel, it doesn't actually take the whole two seconds in practice).

Maybe I'm not following (or maybe this doesn't work, I haven't tested it) but won't this do the trick?
https://nodejs.org/api/fs.html#fs_fs_futimes_fd_atime_mtime_callback

imsnif · 2018-08-03T09:05:52Z

__tests__/commands/install/integration.js

+    await reInstall.init();
+
+    expect(await fs.readJson(`${config.cwd}/node_modules/pkg/package.json`)).toMatchObject({version: '2.0.0'});
+  }));


This test still passes if I revert the changes (speficially in util/fs). Is this a local/os issue for me?

It's a test that ensures that #5723 is still fixed. #6010 was missing tests, so I wanted to be sure that the initial bug wasn't coming back after replacing the commit that was meant to fix it.

There is no test for the perf regression since I'm not sure we can make one that wouldn't be super-flaky 😞 To give you an idea, the different of install time on my machine was 6s, which could potentially come from various other sources (slow network, ...).

Legit. I was just looking for something that would fail if these changes accidentally reverted or changed somehow. Maybe as a unit test for untar-stream when it's moved and for fs?

imsnif · 2018-08-03T09:12:24Z

src/fetchers/tarball-fetcher.js

+    const now = new Date();
+
+    const fs = require('fs');
+    const patchedFs = Object.assign({}, fs, {


I agree this is a good solution in regards to tar-fs. It does kind of bloat the file a little. Do you think it'll be possible to move untar-stream outside somehow?

* Revert "fix(util/fs): use file content instead of mtime to determine equality (#6010)" This reverts commit c53d039. * Bumps the cache version * Forces the mtime to be based on the time the archives got fetched * Fixes subseconds time assignment (nodejs/node#22070) * Adds regression tests for #5723 * Fixes tests * Fixes test on architectures that don't support subsecond precision

Maël Nison added 5 commits August 1, 2018 17:00

Revert "fix(util/fs): use file content instead of mtime to determine …

93fe16c

…equality (yarnpkg#6010)" This reverts commit c53d039.

Bumps the cache version

d27b8cd

Forces the mtime to be based on the time the archives got fetched

c0ff7cf

Fixes subseconds time assignment (nodejs/node#22070)

f6a17f7

Adds regression tests for yarnpkg#5723

324ec4e

arcanis requested a review from imsnif August 1, 2018 19:36

arcanis mentioned this pull request Aug 1, 2018

yarn 1.9.2 takes a long time on linking dependencies #6177

Closed

BYK reviewed Aug 1, 2018

View reviewed changes

Fixes tests

30542c4

arcanis force-pushed the fix-perfs branch from 8f75025 to 30542c4 Compare August 2, 2018 09:37

Fixes test on architectures that don't support subsecond precision

29571d0

arcanis merged commit 15a438d into yarnpkg:master Aug 3, 2018

imsnif reviewed Aug 3, 2018

View reviewed changes

This was referenced Aug 3, 2018

Yarn 1.9.2 really slow when adding packages #6210

Closed

Error releasing v1.9.3 #6217

Closed

arcanis pushed a commit that referenced this pull request Aug 3, 2018

Fixes a test that broke after cherry-picking #6204

424bd20

This was referenced Aug 3, 2018

yarn-chocolatey #55 failed #6223

Closed

yarn-homebrew #50 failed #6224

Closed

shiftkey mentioned this pull request Aug 9, 2018

bump yarn again desktop/desktop#5364

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Fix perf regression #6204

Fix perf regression #6204

arcanis commented Aug 1, 2018 •

edited

Loading

buildsize bot commented Aug 1, 2018

BYK left a comment

BYK Aug 1, 2018

arcanis Aug 1, 2018

BYK Aug 1, 2018

arcanis Aug 1, 2018

Daniel15 Aug 2, 2018 •

edited

Loading

arcanis Aug 2, 2018

imsnif Aug 3, 2018

arcanis Aug 3, 2018

arcanis commented Aug 1, 2018 •

edited

Loading

acao commented Aug 2, 2018

arcanis commented Aug 2, 2018 •

edited

Loading

arcanis commented Aug 3, 2018

imsnif left a comment

imsnif Aug 3, 2018

arcanis Aug 3, 2018

imsnif Aug 3, 2018

imsnif Aug 3, 2018

arcanis Aug 3, 2018

imsnif Aug 3, 2018

imsnif Aug 3, 2018

Fix perf regression #6204

Fix perf regression #6204

Conversation

arcanis commented Aug 1, 2018 • edited Loading

buildsize bot commented Aug 1, 2018

BYK left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Daniel15 Aug 2, 2018 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

arcanis commented Aug 1, 2018 • edited Loading

acao commented Aug 2, 2018

arcanis commented Aug 2, 2018 • edited Loading

arcanis commented Aug 3, 2018

imsnif left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

arcanis commented Aug 1, 2018 •

edited

Loading

Daniel15 Aug 2, 2018 •

edited

Loading

arcanis commented Aug 1, 2018 •

edited

Loading

arcanis commented Aug 2, 2018 •

edited

Loading