yarn is very quick only from the third invocation #2054

mgol · 2016-11-28T14:12:02Z

Do you want to request a feature or report a bug?

A performance issue, maybe a bug.

What is the current behavior?

Running yarn on a project with no node_modules and the yarn cache cleared gets quick (<1s) only from the third try forward.

If the current behavior is a bug, please provide the steps to reproduce.

These are timings on https://github.com/angular/angular.js/:

$ time yarn --ignore-scripts
yarn --ignore-scripts  28.22s user 21.07s system 125% cpu 39.178 total
$ time yarn --ignore-scripts
yarn --ignore-scripts  6.49s user 2.68s system 120% cpu 7.583 total
$ time yarn --ignore-scripts
yarn --ignore-scripts  0.87s user 0.07s system 70% cpu 1.321 total
$ time yarn --ignore-scripts
yarn --ignore-scripts  0.86s user 0.07s system 70% cpu 1.313 total

What is the expected behavior?

It should be quick from the second try.

Performance is one thing but what worries me most is that yarn is supposed to be idempotent on a project with already installed dependencies and a populated cache (which should happen during the first run). So where does this delay come from?

Please mention your node.js, yarn and operating system version.
Node 6.9.1, yarn 0.17.9, macOS 10.12.1 (16B2555)

The text was updated successfully, but these errors were encountered:

kzc · 2016-11-29T10:23:44Z

Seems to be reaching steady state.

Between yarn invocation 1 and 2 node_modules is modified - module hierarchy and versions change.
Between yarn invocation 2 and 3 node_modules remains the same.
yarn.lock remains the same for all yarn invocations (same shasum)

rm -rf node_modules yarn.lock

time (yarn --ignore-scripts --no-progress --no-emoji >/dev/null 2>&1)
shasum yarn.lock
npm ls > 1.txt 2>/dev/null

time (yarn --ignore-scripts --no-progress --no-emoji >/dev/null 2>&1)
shasum yarn.lock
npm ls > 2.txt 2>/dev/null

time (yarn --ignore-scripts --no-progress --no-emoji >/dev/null 2>&1)
shasum yarn.lock
npm ls > 3.txt 2>/dev/null

# see changes
diff -U 0 1.txt 2.txt 

# no changes
diff -U 0 2.txt 3.txt

kzc · 2016-11-29T10:42:05Z

It doesn't appear to be deterministic. Looks like a bug.

DenisGorbachev · 2016-11-29T15:04:37Z

I'm investigating it. The reproduction behavior is not stable: sometimes it runs quickly on the second time, sometimes on third time:

starfall@nx ~/workspace/reproductions/yarnpkg/yarn/issues/2054/test $ rm -rf node_modules yarn.lock && ~/workspace/yarn/bin/yarn --no-progress --ignore-scripts --no-emoji  && ~/workspace/yarn/bin/yarn --no-progress --ignore-scripts --no-emoji && ~/workspace/yarn/bin/yarn --no-progress --ignore-scripts --no-emoji
yarn install v0.18.0-0
info No lockfile found.
[1/4] Resolving packages...
warning [email protected]: Either use gulp-tap or gulp-flatmap, depending on your needs
warning grunt-ddescribe-iit > [email protected]: use [cross-spawn](https://github.com/IndigoUnited/node-cross-spawn) or [cross-spawn-async](https://github.com/IndigoUnited/node-cross-spawn-async) instead.
warning gulp > vinyl-fs > glob-stream > [email protected]: Please update to minimatch 3.0.2 or higher to avoid a RegExp DoS issue
warning jasmine-node > gaze > globule > [email protected]: Please update to minimatch 3.0.2 or higher to avoid a RegExp DoS issue
warning jasmine-node > gaze > globule > glob > [email protected]: graceful-fs v3.0.0 and before will fail on node releases >= v7.0. Please update to graceful-fs@^4.0.0 as soon as possible. Use 'npm ls graceful-fs' to find it in the tree.
warning karma-sauce-launcher > wd > request > [email protected]: use uuid module instead
[2/4] Fetching packages...
warning [email protected]: The platform "linux" is incompatible with this module.
info "[email protected]" is an optional dependency and failed compatibility check. Excluding it from installation.
[3/4] Linking dependencies...
[4/4] Building fresh packages...
warning Ignored scripts due to flag.
success Saved lockfile.
Done in 9.60s.
yarn install v0.18.0-0
[1/4] Resolving packages...
success Already up-to-date.
Done in 0.31s.
yarn install v0.18.0-0
[1/4] Resolving packages...
success Already up-to-date.
Done in 0.46s.


starfall@nx ~/workspace/reproductions/yarnpkg/yarn/issues/2054/test $ rm -rf node_modules yarn.lock && ~/workspace/yarn/bin/yarn --no-progress --ignore-scripts --no-emoji  && ~/workspace/yarn/bin/yarn --no-progress --ignore-scripts --no-emoji && ~/workspace/yarn/bin/yarn --no-progress --ignore-scripts --no-emoji
yarn install v0.18.0-0
info No lockfile found.
[1/4] Resolving packages...
warning [email protected]: Either use gulp-tap or gulp-flatmap, depending on your needs
warning grunt-ddescribe-iit > [email protected]: use [cross-spawn](https://github.com/IndigoUnited/node-cross-spawn) or [cross-spawn-async](https://github.com/IndigoUnited/node-cross-spawn-async) instead.
warning jasmine-node > gaze > globule > [email protected]: Please update to minimatch 3.0.2 or higher to avoid a RegExp DoS issue
warning jasmine-node > gaze > globule > glob > [email protected]: graceful-fs v3.0.0 and before will fail on node releases >= v7.0. Please update to graceful-fs@^4.0.0 as soon as possible. Use 'npm ls graceful-fs' to find it in the tree.
warning gulp > vinyl-fs > glob-stream > [email protected]: Please update to minimatch 3.0.2 or higher to avoid a RegExp DoS issue
warning karma-sauce-launcher > wd > request > [email protected]: use uuid module instead
[2/4] Fetching packages...
warning [email protected]: The platform "linux" is incompatible with this module.
info "[email protected]" is an optional dependency and failed compatibility check. Excluding it from installation.
[3/4] Linking dependencies...
[4/4] Building fresh packages...
warning Ignored scripts due to flag.
success Saved lockfile.
Done in 7.90s.
yarn install v0.18.0-0
[1/4] Resolving packages...
[2/4] Fetching packages...
warning [email protected]: The platform "linux" is incompatible with this module.
info "[email protected]" is an optional dependency and failed compatibility check. Excluding it from installation.
[3/4] Linking dependencies...
[4/4] Building fresh packages...
warning Ignored scripts due to flag.
Done in 3.35s.
yarn install v0.18.0-0
[1/4] Resolving packages...
success Already up-to-date.
Done in 0.38s.

Seems like this bug is related to Fetching packages step. Maybe something changes in npm registry between the runs?

kzc · 2016-11-29T16:55:42Z

Seems like this bug is related to Fetching packages step. Maybe something changes in npm registry between the runs?

Even if that's the case each subsequent yarn invocation should yield the same node_modules as bound by the constraints in yarn.lock (which doesn't change between runs). But in the second run many modules are changing versions and relative location in the modules hierarchy.

For the second yarn invocation why must yarn perform an internet operation at all? Since all the constraints should have been satisfied by the first run it should behave as if it had the --offline flag and perform no network operations and yield the same node_modules.

DenisGorbachev · 2016-11-30T08:14:32Z

While testing, I've encountered a non-reproducible error:

error [email protected]: The engine "node" is incompatible with this module. Expected version ">=6".
error Found incompatible module

Definitely something weird is going on...

DenisGorbachev · 2016-11-30T18:17:57Z

My findings so far: this.resolver.packages has the same amount of packages (1382) each time yarn runs, but this.resolver.getManifests returns a different amount of manifests (1087, 1083... there's an obvious race condition).

FYI, I'm using the following command to check the differences between yarn invocations:

for i in `seq 3`; do export FILENAME=$(date +"%s") && rm -rf node_modules yarn.lock && ~/workspace/yarn/bin/yarn --no-progress --ignore-scripts --no-emoji >> ../$FILENAME.1.log && ~/workspace/yarn/bin/yarn --no-progress --ignore-scripts --no-emoji >> ../$FILENAME.2.log && sort ../$FILENAME.1.log > ../$FILENAME.1.log.sorted.log && sort ../$FILENAME.2.log > ../$FILENAME.2.log.sorted.log && diff -Naur ../$FILENAME.1.log.sorted.log ../$FILENAME.2.log.sorted.log > ../$FILENAME.diff.log; done

DenisGorbachev · 2016-11-30T18:19:11Z

I'll be able to take another look at the weekend, if nobody comes up with a solution.

ghost · 2017-01-09T23:06:27Z

I'm encountering the same behavior with yarn. On first and second invocations of yarn install, yarn is running Linking dependencies..., I assume copying all files into the node_modules directory (around 33,000 files)

Second invocation of yarn install:

$ time yarn install
yarn install v0.18.1
[1/4] Resolving packages...
[2/4] Fetching packages...
warning [email protected]: The platform "win32" is incompatible with this module.
info "[email protected]" is an optional dependency and failed compatibility check. Excluding it from installation.
[3/4] Linking dependencies...
warning Incorrect peer dependency "webpack@^2.1.0-beta.19".
[4/4] Building fresh packages...
Done in 181.94s.

Third invocation of yarn install behaves as I would have expected the second invocation:

$ time yarn install
yarn install v0.18.1
[1/4] Resolving packages...
success Already up-to-date.
Done in 4.92s.

Please mention your node.js, yarn and operating system version.

Node - 6.9.3
OS - Windows 7
Yarn - 0.18.1

IgorAufricht · 2017-01-18T10:45:49Z

I've recently seen this behaviour as well. I can repeatedly reproduce it with the following package.json:

{
  "devDependencies": {
    "grunt": "^1.0.1",
    "jasmine": "^2.5.3"
  }
}

The problem happens with no lock file:

$ rm-rf node_modules/ yarn.lock

$ yarn
yarn install v0.19.1
info No lockfile found.
warning No license field
[1/4] Resolving packages...
[2/4] Fetching packages...
[3/4] Linking dependencies...
[4/4] Building fresh packages...
success Saved lockfile.
Done in 3.94s.

$ yarn
yarn install v0.19.1
warning No license field
[1/4] Resolving packages...
[2/4] Fetching packages...
[3/4] Linking dependencies...
[4/4] Building fresh packages...
Done in 2.56s.

$ yarn
yarn install v0.19.1
warning No license field
[1/4] Resolving packages...
success Already up-to-date.
Done in 0.29s.

But with the lock file present it works as expected:

$ rm -rf node_modules/

$ yarn
yarn install v0.19.1
warning No license field
[1/4] Resolving packages...
[2/4] Fetching packages...
[3/4] Linking dependencies...
[4/4] Building fresh packages...
Done in 2.69s.

$ yarn
yarn install v0.19.1
warning No license field
[1/4] Resolving packages...
success Already up-to-date.
Done in 0.27s.

Please mention your node.js, yarn and operating system version.
node.js v6.3.0
yarn 0.19.1
Windows 7 x64 (running yarn from Git Bash)

ghost · 2017-01-23T19:20:09Z

@IgorAufricht that is a great point. This issue only happens if the project does not have a yarn.lock file to begin with. I just re-tested my earlier project, and yarn install completes as expected on the second install when the project already has a yarn.lock file.

edmorley · 2017-03-09T00:32:57Z

I believe the issue I'm seeing is the same as this (ie if yarn.lock doesn't already exist, the stable state is only reached after the 2nd yarn invocation).

Observations that may be useful:

The yarn.lock file remains unchanged once created
However the contents of .yarn-integrity changes between the 1st and 2nd yarn invocations (and remains unchanged after that).

STR:
Using this package.json, nodejs 7.7.1, yarn 0.21.3, under Ubuntu 14.04.

$ rm -rf node_modules/ yarn.lock

$ yarn
yarn install v0.21.3
info No lockfile found.
[1/4] Resolving packages...
warning grunt-html-angular-validate > html-angular-validate > globule > [email protected]: Please update to minimatch 3.0.2 or higher to avoid a RegExp DoS issue
warning grunt-html-angular-validate > html-angular-validate > globule > glob > [email protected]: Please update to minimatch 3.0.2 or higher to avoid a RegExp DoS issue
[2/4] Fetching packages...
warning [email protected]: The platform "linux" is incompatible with this module.
info "[email protected]" is an optional dependency and failed compatibility check. Excluding it from installation.
[3/4] Linking dependencies...
[4/4] Building fresh packages...
success Saved lockfile.
Done in 22.63s.

$ sha256sum yarn.lock
0486e32773a05778347a00906c14f29a47cc69eae60c75bd442353fde6a699c2  yarn.lock

$ cat node_modules/.yarn-integrity; echo
964b624365d4fec753e0c96ff9b323122a5f6a9f4f23242f3fc0db26bbdfbe9d

$ yarn
yarn install v0.21.3
[1/4] Resolving packages...
[2/4] Fetching packages...
warning [email protected]: The platform "linux" is incompatible with this module.
info "[email protected]" is an optional dependency and failed compatibility check. Excluding it from installation.
[3/4] Linking dependencies...
[4/4] Building fresh packages...
Done in 6.99s.

$ sha256sum yarn.lock
0486e32773a05778347a00906c14f29a47cc69eae60c75bd442353fde6a699c2  yarn.lock

$ cat node_modules/.yarn-integrity; echo
aefe649c0b8eb9cf85bb7ac951dca0764e161f9cf007de6e869c536a9b7c93d3

$ yarn
yarn install v0.21.3
[1/4] Resolving packages...
success Already up-to-date.
Done in 0.87s.

$ sha256sum yarn.lock
0486e32773a05778347a00906c14f29a47cc69eae60c75bd442353fde6a699c2  yarn.lock

$ cat node_modules/.yarn-integrity; echo
aefe649c0b8eb9cf85bb7ac951dca0764e161f9cf007de6e869c536a9b7c93d3

edmorley · 2017-03-09T01:53:50Z

I was able to reduce that testcase to:

{
  "devDependencies": {
    "browserify": "^13.1.1",
    "eslint": "3.8.0",
    "watchify": "^3.8.0"
  }
}

Note: devDependencies rather than dependencies was required to be able to reproduce (for this set of packages at least).

In addition to .yarn-integrity changing after the second yarn invocation, the nested concat-stream package was removed (it also exists at the top level):

$ diff -r node_modules_initial/ node_modules/
Only in node_modules_initial/eslint/node_modules: concat-stream
diff -r node_modules_initial/.yarn-integrity node_modules/.yarn-integrity
1c1
< eb17f440cb23a037fe258c07d7f950889a2290d2394456accfcd37d737f83382
\ No newline at end of file
---
> 4b6c3265db04c9a3b49661a8dd0ce2e91bb9931e6c247fd4b1f3b1b53b3ac323
\ No newline at end of file

bestander · 2017-07-06T02:13:45Z

Thanks for the repro steps.
Indeed Yarn did some optimization on a second yarn install.
This should be fixed in [email protected]

kzc · 2017-07-06T05:01:06Z

This appears to be the fix: #3729

mgol mentioned this issue Nov 28, 2016

chore(*): use Yarn for dependency management angular/angular.js#15435

Merged

3 tasks

bestander closed this as completed Jul 6, 2017

edmorley mentioned this issue Jul 6, 2017

Yarn cache ignored across builds travis-ci/travis-ci#8014

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

yarn is very quick only from the third invocation #2054

yarn is very quick only from the third invocation #2054

mgol commented Nov 28, 2016 •

edited

Loading

kzc commented Nov 29, 2016

kzc commented Nov 29, 2016

DenisGorbachev commented Nov 29, 2016

kzc commented Nov 29, 2016

DenisGorbachev commented Nov 30, 2016

DenisGorbachev commented Nov 30, 2016

DenisGorbachev commented Nov 30, 2016

ghost commented Jan 9, 2017

IgorAufricht commented Jan 18, 2017

ghost commented Jan 23, 2017

edmorley commented Mar 9, 2017 •

edited

Loading

edmorley commented Mar 9, 2017 •

edited

Loading

bestander commented Jul 6, 2017

kzc commented Jul 6, 2017

yarn is very quick only from the third invocation #2054

yarn is very quick only from the third invocation #2054

Comments

mgol commented Nov 28, 2016 • edited Loading

kzc commented Nov 29, 2016

kzc commented Nov 29, 2016

DenisGorbachev commented Nov 29, 2016

kzc commented Nov 29, 2016

DenisGorbachev commented Nov 30, 2016

DenisGorbachev commented Nov 30, 2016

DenisGorbachev commented Nov 30, 2016

ghost commented Jan 9, 2017

IgorAufricht commented Jan 18, 2017

ghost commented Jan 23, 2017

edmorley commented Mar 9, 2017 • edited Loading

edmorley commented Mar 9, 2017 • edited Loading

bestander commented Jul 6, 2017

kzc commented Jul 6, 2017

mgol commented Nov 28, 2016 •

edited

Loading

edmorley commented Mar 9, 2017 •

edited

Loading

edmorley commented Mar 9, 2017 •

edited

Loading