Skip to content

Conversation

@vsemozhetbyt
Copy link
Contributor

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

functiontestFuncDeopt(namedArg){constbaz=arguments[0];// condition 1namedArg='bar';// condition 3functioninner(){returnnamedArg;}// condition 2}for(leti=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):

functiontestFuncDeopt(namedArg){constbaz=arguments[0];// condition 1functioninner(){returnnamedArg;}// condition 2}for(leti=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):

constreadFile=require('fs').readFile;constcb=()=>{};for(leti=0;i<1e3;i++)readFile(__filename,cb);
constwriteFile=require('fs').writeFile;constcb=()=>{};for(leti=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-botnodejs-github-bot added the fs Issues and PRs related to the fs subsystem / file system. label Mar 3, 2017
@vsemozhetbyt
Copy link
ContributorAuthor

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';constcommon=require('../common.js');constfs=require('fs');constpath=require('path');constfilePath=path.join(__dirname,'read-write-file-params.txt');constdata=Buffer.from('1');constoptions={};constconfigs={n: [1e3],methodName: ['readFile','writeFile'],params: ['withOptions','withoutOptions'],};constbench=common.createBenchmark(main,configs);functionmain(conf){constn=+conf.n;constmethodName=conf.methodName;constparams=conf.params;letcounter=n;constcallbacks={readFile: {withOptions(){if(counter--)fs.readFile(filePath,options,callback);elsebench.end(n);},withoutOptions(){if(counter--)fs.readFile(filePath,callback);elsebench.end(n);},},writeFile: {withOptions(){if(counter--)fs.writeFile(filePath,data,options,callback);elsebench.end(n);},withoutOptions(){if(counter--)fs.writeFile(filePath,data,callback);elsebench.end(n);},},};constcallback=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
ContributorAuthor

@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
ContributorAuthor

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
ContributorAuthor

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

@vsemozhetbytvsemozhetbyt deleted the fix-fs-arguments-deopt branch March 10, 2017 12:21
Sign up for freeto join this conversation on GitHub. Already have an account? Sign in to comment

Labels

fsIssues and PRs related to the fs subsystem / file system.

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants

@vsemozhetbyt@joyeecheung@nodejs-github-bot