Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

fs: fix deoptimizing use of arguments #11678

Closed
wants to merge 1 commit into from
Closed

fs: fix deoptimizing use of arguments #11678

wants to merge 1 commit into from

Conversation

vsemozhetbyt
Copy link
Contributor

@vsemozhetbyt vsemozhetbyt commented Mar 3, 2017

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):

  1. arguments mention (any: arguments, arguments[valid_index], arguments.length).
  2. Named parameter leaking in a lower scope.
  3. 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):

  1. Reading arguments[valid_index] (not arguments or arguments.length).
  2. 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

  1. fs.readFile() has the conditions for the both cases I and II.
  2. fs.writeFile() has the conditions for the both cases I and II.
  3. 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.

@nodejs-github-bot nodejs-github-bot added the fs Issues and PRs related to the fs subsystem / file system. label Mar 3, 2017
@vsemozhetbyt
Copy link
Contributor Author

vsemozhetbyt commented Mar 3, 2017

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

@joyeecheung
Copy link
Member

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

@vsemozhetbyt
Copy link
Contributor Author

@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().

@vsemozhetbyt
Copy link
Contributor Author

vsemozhetbyt commented Mar 5, 2017

To sum up the puzzles:

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

// cc @nodejs/v8

@vsemozhetbyt
Copy link
Contributor Author

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).

@vsemozhetbyt vsemozhetbyt deleted the fix-fs-arguments-deopt branch March 10, 2017 12:21
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
fs Issues and PRs related to the fs subsystem / file system.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants