fs: fix deoptimizing use of `arguments` by vsemozhetbyt · Pull Request #11678 · nodejs/node · GitHub

Checklist

make -j4 test (UNIX), or vcbuild test (Windows) passes
tests and/or benchmarks are included
commit message follows commit guidelines

Affected core subsystem(s)

fs, benchmark

This is a twisted case that puzzles me for some time. I am not sure how it should proceed.

Prehistory / context

Thre are two deoptimization cases concerning arguments that affect fs module. They have similar conditions and affect almost the same fs functions.

I. 'Assignment to parameter in arguments object' in strict mode.

Previously this bailout was reported only for sloppy mode: see here and here. However, it seems there is some combination of circumstances for strict mode too.

There should be 3 conditions (which partly intersect with case II below):

arguments mention (any: arguments, arguments[valid_index], arguments.length).
Named parameter leaking in a lower scope.
Named parameter reassignment (it should be reassigned in the parent scope; reassignment in the lower scope does not cause deopt).

How to check (run with --trace_opt --trace_deopt and see the output):

function testFuncDeopt(namedArg) {
  const baz = arguments[0]; // condition 1
  namedArg = 'bar'; // condition 3
  function inner() { return namedArg; } // condition 2
}
for (let i = 0; i < 1e3; i++) testFuncDeopt('foo');

Versions impact:

v8 4.5.103.45 (Node.js 4.8.0) — affected (disabled optimization).
v8 5.1.281.93 (Node.js 6.10.0) — partly affected (deopt, then new optimization).
v8 5.5.372.41 (Node.js 7.7.1) — affected (disabled optimization).
v8 5.6.326.55 (Node.js 8.0.0-nightly / master) — partly affected, partly replaced by the case II (see below).
v8 5.8.202 (Node.js 8.0.0-pre vee-eight-lkgr) — partly affected, partly replaced by the case II (see below).

II. 'Bad value context for arguments value'.

This is a new deopt introduced by the v8 5.6 (see the upstream report; if I get this comment right, this will not be fixed till the new TurboFan pipeline hits the default use, i.e. till v8 5.9 (?)).

There should be 2 conditions (which partly intersect with case I):

Reading arguments[valid_index] (not arguments or arguments.length).
Named parameter leaking in a lower scope.

How to check (run with --trace_opt --trace_deopt and see the output):

function testFuncDeopt(namedArg) {
  const baz = arguments[0]; // condition 1
  function inner() { return namedArg; } // condition 2
}
for (let i = 0; i < 1e3; i++) testFuncDeopt('foo');

Versions impact:

v8 5.6.326.55 (Node.js 8.0.0-nightly / master) — affected.
v8 5.8.202 (Node.js 8.0.0-pre vee-eight-lkgr) — affected.

Node.js libs impact

I've checked the libs for these two cases and have found out only 4 functions affected: 3 from fs (this PR) and 1 from _http_agent (will address in another PR later on).

fs lib impact

fs.readFile() has the conditions for the both cases I and II.
fs.writeFile() has the conditions for the both cases I and II.
Inner writeAll() has the conditions for the case I only.

I've tried to eliminate both the cases, so I had two variants of addressing: remove using of arguments or use intermediate variables for named parameters to transfer them into the lower scope. Both ways have the same benchmark results, so I've selected the first way (the second seems to be much more complicated and lumbering).

For the fs.readFile() and fs.writeFile() I've replaced arguments by conditional using of named parameters.

As to writeAll(), I've noticed that the check in the first line is redundant: writeAll() is called only by the fs.writeFile() method (which has its own check that throws if callback is not provided) and by the writeAll() itself with already checked callback. So we can remove the check and the intermediate parameter.

All tests are passed with the proposed changes (after this PR landed).

You can check deoptimization and fixes with these tests (run with --trace_opt --trace_deopt and see the output):

const readFile = require('fs').readFile;
const cb = () => {};
for (let i = 0; i < 1e3; i++) readFile(__filename, cb);

const writeFile = require('fs').writeFile;
const cb = () => {};
for (let i = 0; i < 1e3; i++) writeFile('testfile.txt', '1', cb);

Performance puzzle

After running a newly created benchmark, I've found out that the optimized fs.readFile() runs much slower than the unoptimized one on the master. fs.writeFile() has flaky results.

Some examples:

                                                                                 improvement confidence      p.value
 fs\\read-write-file-params.js withOptions="false" methodName="readFile" n=1000     -13.61 %        *** 3.628276e-06
 fs\\read-write-file-params.js withOptions="false" methodName="writeFile" n=1000      2.13 %            7.127870e-01
 fs\\read-write-file-params.js withOptions="true" methodName="readFile" n=1000       -9.00 %         ** 2.312356e-03
 fs\\read-write-file-params.js withOptions="true" methodName="writeFile" n=1000       2.38 %            5.706614e-01

                                                                                 improvement confidence     p.value
 fs\\read-write-file-params.js withOptions="false" methodName="readFile" n=1000      -9.47 %         ** 0.002279570
 fs\\read-write-file-params.js withOptions="false" methodName="writeFile" n=1000     10.82 %          * 0.030607596
 fs\\read-write-file-params.js withOptions="true" methodName="readFile" n=1000       -9.10 %         ** 0.004372376
 fs\\read-write-file-params.js withOptions="true" methodName="writeFile" n=1000      -3.62 %            0.391912744

                                                                                 improvement confidence     p.value
 fs\\read-write-file-params.js withOptions="false" methodName="readFile" n=1000      -6.93 %          * 0.034545206
 fs\\read-write-file-params.js withOptions="false" methodName="writeFile" n=1000     -0.62 %            0.902353347
 fs\\read-write-file-params.js withOptions="true" methodName="readFile" n=1000      -11.37 %         ** 0.001215041
 fs\\read-write-file-params.js withOptions="true" methodName="writeFile" n=1000      -0.38 %            0.945159471

                                                                                 improvement confidence      p.value
 fs\\read-write-file-params.js withOptions="false" methodName="readFile" n=1000      -7.67 %          * 0.0126620954
 fs\\read-write-file-params.js withOptions="false" methodName="writeFile" n=1000     -0.72 %            0.8910846613
 fs\\read-write-file-params.js withOptions="true" methodName="readFile" n=1000      -10.54 %        *** 0.0009612553
 fs\\read-write-file-params.js withOptions="true" methodName="writeFile" n=1000      -8.19 %            0.0663402207

Moreover, the fs.readFile() tests show a very strange new deoptimization: it happens after all the cycle runs, so it hardly has any performance impact but can be an evidence of some murky processes. See more in this issue.

I am not sure what to do with all this data. Maybe my benchmark is just wrong (I've gone over some alterations with no noticeable changes). So I just share it with the team by this PR to draw more thoughts. Sorry for any mess.

Refs: vhf/v8-bailout-reasons#15 Refs: https://bugs.chromium.org/p/v8/issues/detail?id=6010

FWIW, I've tried a benchmark without concurrent reads/writes, but it gives just more flaky results:

Code (click me):

'use strict';

const common = require('../common.js');
const fs = require('fs');
const path = require('path');

const filePath = path.join(__dirname, 'read-write-file-params.txt');
const data = Buffer.from('1');
const options = {};

const configs = {
  n: [1e3],
  methodName: ['readFile', 'writeFile'],
  params: ['withOptions', 'withoutOptions'],
};

const bench = common.createBenchmark(main, configs);

function main(conf) {
  const n = +conf.n;
  const methodName = conf.methodName;
  const params = conf.params;

  let counter = n;

  const callbacks = {
    readFile: {
      withOptions() {
        if (counter--) fs.readFile(filePath, options, callback);
        else bench.end(n);
      },
      withoutOptions() {
        if (counter--) fs.readFile(filePath, callback);
        else bench.end(n);
      },
    },
    writeFile: {
      withOptions() {
        if (counter--) fs.writeFile(filePath, data, options, callback);
        else bench.end(n);
      },
      withoutOptions() {
        if (counter--) fs.writeFile(filePath, data, callback);
        else bench.end(n);
      },
    },
  };

  const callback = callbacks[methodName][params];

  bench.start();
  callback();
}

Examples of results (click me):

                                                                                      improvement confidence   p.value
 fs\\read-write-file-params2.js params="withOptions" methodName="readFile" n=1000          5.52 %            0.4602363
 fs\\read-write-file-params2.js params="withOptions" methodName="writeFile" n=1000        -9.82 %            0.2246384
 fs\\read-write-file-params2.js params="withoutOptions" methodName="readFile" n=1000      -1.39 %            0.7883977
 fs\\read-write-file-params2.js params="withoutOptions" methodName="writeFile" n=1000      0.72 %            0.9135858

                                                                                      improvement confidence   p.value
 fs\\read-write-file-params2.js params="withOptions" methodName="readFile" n=1000         -1.11 %            0.8092441
 fs\\read-write-file-params2.js params="withOptions" methodName="writeFile" n=1000        -7.42 %            0.1914968
 fs\\read-write-file-params2.js params="withoutOptions" methodName="readFile" n=1000       3.78 %            0.4990780
 fs\\read-write-file-params2.js params="withoutOptions" methodName="writeFile" n=1000      3.98 %            0.6091475

                                                                                      improvement confidence   p.value
 fs\\read-write-file-params2.js params="withOptions" methodName="readFile" n=1000          2.94 %            0.5826245
 fs\\read-write-file-params2.js params="withOptions" methodName="writeFile" n=1000         6.98 %            0.2660900
 fs\\read-write-file-params2.js params="withoutOptions" methodName="readFile" n=1000     -10.11 %            0.1240814
 fs\\read-write-file-params2.js params="withoutOptions" methodName="writeFile" n=1000     -4.94 %            0.4488671

About the flakiness..you can try running it master against master to be more certain about it :)

@joyeecheung
Master against master: both benchmarks are flaky without any 'confidence' (with one small exception).

Synk sycle (benchmark from the PR):

                                                                                 improvement confidence   p.value
 fs\\read-write-file-params.js withOptions="false" methodName="readFile" n=1000       1.62 %            0.5020186
 fs\\read-write-file-params.js withOptions="false" methodName="writeFile" n=1000      1.09 %            0.8146558
 fs\\read-write-file-params.js withOptions="true" methodName="readFile" n=1000       -2.67 %            0.3244180
 fs\\read-write-file-params.js withOptions="true" methodName="writeFile" n=1000       5.74 %            0.2507602

                                                                                 improvement confidence   p.value
 fs\\read-write-file-params.js withOptions="false" methodName="readFile" n=1000      -2.82 %            0.4915746
 fs\\read-write-file-params.js withOptions="false" methodName="writeFile" n=1000     -0.64 %            0.8944677
 fs\\read-write-file-params.js withOptions="true" methodName="readFile" n=1000        3.06 %            0.2522428
 fs\\read-write-file-params.js withOptions="true" methodName="writeFile" n=1000      -2.02 %            0.6443562

                                                                                 improvement confidence    p.value
 fs\\read-write-file-params.js withOptions="false" methodName="readFile" n=1000      -4.15 %            0.25131635
 fs\\read-write-file-params.js withOptions="false" methodName="writeFile" n=1000     -3.98 %            0.38642937
 fs\\read-write-file-params.js withOptions="true" methodName="readFile" n=1000       -1.84 %            0.51933610
 fs\\read-write-file-params.js withOptions="true" methodName="writeFile" n=1000       7.91 %            0.05463895

Asynk sycle (benchmark from the comment above):

                                                                                      improvement confidence   p.value
 fs\\read-write-file-params2.js params="withOptions" methodName="readFile" n=1000         -4.43 %            0.5957750
 fs\\read-write-file-params2.js params="withOptions" methodName="writeFile" n=1000         4.84 %            0.6545475
 fs\\read-write-file-params2.js params="withoutOptions" methodName="readFile" n=1000      -2.33 %            0.7239557
 fs\\read-write-file-params2.js params="withoutOptions" methodName="writeFile" n=1000     -3.56 %            0.6820713

                                                                                      improvement confidence   p.value
 fs\\read-write-file-params2.js params="withOptions" methodName="readFile" n=1000          6.05 %            0.3755462
 fs\\read-write-file-params2.js params="withOptions" methodName="writeFile" n=1000        -2.26 %            0.7409838
 fs\\read-write-file-params2.js params="withoutOptions" methodName="readFile" n=1000      -2.60 %            0.7078106
 fs\\read-write-file-params2.js params="withoutOptions" methodName="writeFile" n=1000     -7.56 %            0.1720084
                                                                                      improvement confidence    p.value
 fs\\read-write-file-params2.js params="withOptions" methodName="readFile" n=1000         11.05 %            0.08335120
 fs\\read-write-file-params2.js params="withOptions" methodName="writeFile" n=1000       -12.96 %          * 0.02071468
 fs\\read-write-file-params2.js params="withoutOptions" methodName="readFile" n=1000      11.17 %            0.11986225
 fs\\read-write-file-params2.js params="withoutOptions" methodName="writeFile" n=1000     -1.61 %            0.82095991

While master against fix: async benchmark is flaky without any 'confidence', sync benchmark shows degradation of the fs.readFile() with variable 'confidence' and is flaky for fs.writeFile().

To sum up the puzzles:

Why the identical simple change downgrades fs.readFile() while does not downgrade fs.writeFile()?
Why the optimized fs.readFile() is slower than the unoptimized one?

// cc @nodejs/v8

I will close it as the fixes do not give any performance gain anyway.

Fixing the mentioned deopt in the _http_agent.js also does not prove itself (some context).

fs: fix deoptimizing use of arguments

63ea83f

Refs: vhf/v8-bailout-reasons#15 Refs: https://bugs.chromium.org/p/v8/issues/detail?id=6010

nodejs-github-bot added the fs Issues and PRs related to the fs subsystem / file system. label Mar 3, 2017

vsemozhetbyt closed this Mar 10, 2017

vsemozhetbyt deleted the fix-fs-arguments-deopt branch March 10, 2017 12:21

seishun mentioned this pull request Mar 17, 2017

fs: don't conflate data and callback in fs.appendFile #11607

Closed

3 tasks

fs: fix deoptimizing use of `arguments` by vsemozhetbyt · Pull Request #11678 · nodejs/node · GitHub

Uh oh!

Uh oh!

fs: fix deoptimizing use of arguments - #11678

fs: fix deoptimizing use of arguments#11678
vsemozhetbyt wants to merge 1 commit into
nodejs:masterfrom
vsemozhetbyt:fix-fs-arguments-deopt

vsemozhetbyt commented Mar 3, 2017 •
edited
Loading

Uh oh!

Uh oh!

vsemozhetbyt commented Mar 3, 2017 •
edited
Loading

Uh oh!

Uh oh!

joyeecheung commented Mar 4, 2017

Uh oh!

vsemozhetbyt commented Mar 4, 2017

Uh oh!

vsemozhetbyt commented Mar 5, 2017 •
edited
Loading

Uh oh!

Uh oh!

vsemozhetbyt commented Mar 10, 2017

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

fs: fix deoptimizing use of `arguments` by vsemozhetbyt · Pull Request #11678 · nodejs/node · GitHub

Uh oh!

Uh oh!

fs: fix deoptimizing use of arguments - #11678

fs: fix deoptimizing use of arguments#11678vsemozhetbyt wants to merge 1 commit intonodejs:masternodejs/node:masterfrom vsemozhetbyt:fix-fs-arguments-deoptCopy head branch name to clipboard

Conversation

vsemozhetbyt commented Mar 3, 2017 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Checklist

Affected core subsystem(s)

Prehistory / context

Node.js libs impact

fs lib impact

Performance puzzle

Uh oh!

vsemozhetbyt commented Mar 3, 2017 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

joyeecheung commented Mar 4, 2017

Uh oh!

vsemozhetbyt commented Mar 4, 2017

Uh oh!

vsemozhetbyt commented Mar 5, 2017 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

vsemozhetbyt commented Mar 10, 2017

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

fs: fix deoptimizing use of arguments#11678
vsemozhetbyt wants to merge 1 commit into
nodejs:masterfrom
vsemozhetbyt:fix-fs-arguments-deopt

vsemozhetbyt commented Mar 3, 2017 •
edited
Loading

vsemozhetbyt commented Mar 3, 2017 •
edited
Loading

vsemozhetbyt commented Mar 5, 2017 •
edited
Loading