node icon indicating copy to clipboard operation
node copied to clipboard

console: make console.log resilient to built-in prototypes tempering

Open aduh95 opened this issue 4 years ago • 4 comments

Fixes: https://github.com/nodejs/node/issues/32361

aduh95 avatar Feb 12 '21 18:02 aduh95

Benchmark CI: https://ci.nodejs.org/view/Node.js%20benchmark/job/benchmark-node-micro-benchmarks/944/

aduh95 avatar Feb 12 '21 18:02 aduh95

Do we really need a test for this?

I added the test because it causes significant perf regressions to the events and streams benchmarks:, and if we are going to make that tradeoff, we should have a test otherwise it might be reverted in the future.

                                                                                         confidence improvement accuracy (*)    (**)   (***)
events/ee-emit.jslisteners=5 argc=0 n=2000000                                                     *      3.38 %       ±3.05%  ±4.07%  ±5.31%
events/ee-listeners.jsraw='false' listeners=50 n=5000000                                         **      2.15 %       ±1.54%  ±2.04%  ±2.66%
events/ee-once.jsargc=0 n=20000000                                                              ***    -10.08 %       ±0.88%  ±1.17%  ±1.52%
events/ee-once.jsargc=1 n=20000000                                                              ***     -6.86 %       ±2.52%  ±3.39%  ±4.50%
events/ee-once.jsargc=4 n=20000000                                                              ***     -8.15 %       ±0.99%  ±1.32%  ±1.72%
events/ee-once.jsargc=5 n=20000000                                                              ***     -8.20 %       ±1.36%  ±1.82%  ±2.40%
streams/creation.jskind='transform' n=50000000                                                  ***     -5.39 %       ±2.97%  ±3.96%  ±5.17%
streams/creation.jskind='writable' n=50000000                                                   ***     -8.28 %       ±1.46%  ±1.95%  ±2.55%
streams/readable-boundaryread.jstype='string' n=2000                                              *      4.07 %       ±3.98%  ±5.30%  ±6.90%
                                                                                         confidence improvement accuracy (*)    (**)   (***)
events/ee-add-remove.jsn=1000000                                                                        -2.58 %       ±3.38%  ±4.52%  ±5.93%
events/ee-emit.jslisteners=10 argc=0 n=2000000                                                          -1.35 %       ±2.12%  ±2.85%  ±3.75%
events/ee-emit.jslisteners=10 argc=10 n=2000000                                                          0.18 %       ±0.73%  ±0.97%  ±1.26%
events/ee-emit.jslisteners=10 argc=2 n=2000000                                                           0.88 %       ±1.30%  ±1.73%  ±2.25%
events/ee-emit.jslisteners=10 argc=4 n=2000000                                                           0.20 %       ±0.96%  ±1.28%  ±1.66%
events/ee-emit.jslisteners=1 argc=0 n=2000000                                                            0.52 %       ±3.82%  ±5.10%  ±6.65%
events/ee-emit.jslisteners=1 argc=10 n=2000000                                                           1.31 %       ±3.56%  ±4.74%  ±6.18%
events/ee-emit.jslisteners=1 argc=2 n=2000000                                                            2.08 %       ±4.79%  ±6.38%  ±8.32%
events/ee-emit.jslisteners=1 argc=4 n=2000000                                                            0.29 %       ±4.39%  ±5.84%  ±7.60%
events/ee-emit.jslisteners=5 argc=0 n=2000000                                                     *      3.38 %       ±3.05%  ±4.07%  ±5.31%
events/ee-emit.jslisteners=5 argc=10 n=2000000                                                          -0.32 %       ±2.04%  ±2.72%  ±3.55%
events/ee-emit.jslisteners=5 argc=2 n=2000000                                                           -0.86 %       ±1.72%  ±2.28%  ±2.97%
events/ee-emit.jslisteners=5 argc=4 n=2000000                                                            0.60 %       ±1.50%  ±2.00%  ±2.61%
events/ee-listener-count-on-prototype.jsn=50000000                                                      -1.42 %       ±3.29%  ±4.42%  ±5.82%
events/ee-listeners.jsraw='false' listeners=50 n=5000000                                         **      2.15 %       ±1.54%  ±2.04%  ±2.66%
events/ee-listeners.jsraw='false' listeners=5 n=5000000                                                  2.24 %       ±5.27%  ±7.08%  ±9.35%
events/ee-listeners.jsraw='true' listeners=50 n=5000000                                                 -0.90 %       ±1.67%  ±2.23%  ±2.90%
events/ee-listeners.jsraw='true' listeners=5 n=5000000                                                  -0.41 %       ±2.95%  ±3.92%  ±5.11%
events/ee-once.jsargc=0 n=20000000                                                              ***    -10.08 %       ±0.88%  ±1.17%  ±1.52%
events/ee-once.jsargc=1 n=20000000                                                              ***     -6.86 %       ±2.52%  ±3.39%  ±4.50%
events/ee-once.jsargc=4 n=20000000                                                              ***     -8.15 %       ±0.99%  ±1.32%  ±1.72%
events/ee-once.jsargc=5 n=20000000                                                              ***     -8.20 %       ±1.36%  ±1.82%  ±2.40%
events/eventtarget.jslisteners=10 n=1000000                                                              1.40 %       ±5.79%  ±7.72% ±10.07%
events/eventtarget.jslisteners=1 n=1000000                                                              -1.16 %       ±3.42%  ±4.58%  ±6.00%
events/eventtarget.jslisteners=5 n=1000000                                                               2.71 %       ±5.36%  ±7.20%  ±9.51%
streams/creation.jskind='duplex' n=50000000                                                             -2.42 %       ±2.82%  ±3.75%  ±4.89%
streams/creation.jskind='readable' n=50000000                                                           -2.30 %       ±2.60%  ±3.46%  ±4.50%
streams/creation.jskind='transform' n=50000000                                                  ***     -5.39 %       ±2.97%  ±3.96%  ±5.17%
streams/creation.jskind='writable' n=50000000                                                   ***     -8.28 %       ±1.46%  ±1.95%  ±2.55%
streams/pipe.jsn=5000000                                                                                 1.84 %       ±2.65%  ±3.54%  ±4.63%
streams/pipe-object-mode.jsn=5000000                                                                    -0.61 %       ±4.02%  ±5.36%  ±7.00%
streams/readable-async-iterator.jssync='no' n=100000                                                    -0.65 %       ±2.18%  ±2.90%  ±3.79%
streams/readable-async-iterator.jssync='yes' n=100000                                                   -1.40 %       ±4.42%  ±5.88%  ±7.66%
streams/readable-bigread.jsn=1000                                                                        2.75 %       ±5.48%  ±7.29%  ±9.49%
streams/readable-bigunevenread.jsn=1000                                                                 -2.08 %       ±5.99%  ±7.98% ±10.40%
streams/readable-boundaryread.jstype='buffer' n=2000                                                     1.45 %       ±2.81%  ±3.74%  ±4.87%
streams/readable-boundaryread.jstype='string' n=2000                                              *      4.07 %       ±3.98%  ±5.30%  ±6.90%
streams/readable-readall.jsn=5000                                                                        0.95 %      ±14.35% ±19.09% ±24.85%
streams/readable-unevenread.jsn=1000                                                                     2.20 %       ±3.63%  ±4.84%  ±6.31%
streams/writable-manywrites.jslen=1024 callback='no' writev='no' sync='no' n=2000000                     1.02 %       ±1.78%  ±2.37%  ±3.09%
streams/writable-manywrites.jslen=1024 callback='no' writev='no' sync='yes' n=2000000                   -5.32 %       ±6.95%  ±9.33% ±12.30%
streams/writable-manywrites.jslen=1024 callback='no' writev='yes' sync='no' n=2000000                   -1.82 %       ±2.61%  ±3.47%  ±4.52%
streams/writable-manywrites.jslen=1024 callback='no' writev='yes' sync='yes' n=2000000                  -2.80 %       ±3.67%  ±4.88%  ±6.36%
streams/writable-manywrites.jslen=1024 callback='yes' writev='no' sync='no' n=2000000                    0.68 %       ±1.11%  ±1.48%  ±1.92%
streams/writable-manywrites.jslen=1024 callback='yes' writev='no' sync='yes' n=2000000                   0.13 %       ±3.96%  ±5.27%  ±6.86%
streams/writable-manywrites.jslen=1024 callback='yes' writev='yes' sync='no' n=2000000                  -1.83 %       ±2.45%  ±3.26%  ±4.25%
streams/writable-manywrites.jslen=1024 callback='yes' writev='yes' sync='yes' n=2000000                 -1.68 %       ±3.32%  ±4.42%  ±5.75%
streams/writable-manywrites.jslen=32768 callback='no' writev='no' sync='no' n=2000000                    1.23 %       ±3.97%  ±5.34%  ±7.08%
streams/writable-manywrites.jslen=32768 callback='no' writev='no' sync='yes' n=2000000                  -2.05 %       ±3.50%  ±4.70%  ±6.22%
streams/writable-manywrites.jslen=32768 callback='no' writev='yes' sync='no' n=2000000                  -2.54 %       ±2.61%  ±3.50%  ±4.60%
streams/writable-manywrites.jslen=32768 callback='no' writev='yes' sync='yes' n=2000000                 -0.14 %       ±1.74%  ±2.32%  ±3.02%
streams/writable-manywrites.jslen=32768 callback='yes' writev='no' sync='no' n=2000000                  -0.37 %       ±1.65%  ±2.20%  ±2.88%
streams/writable-manywrites.jslen=32768 callback='yes' writev='no' sync='yes' n=2000000                 -1.69 %       ±3.43%  ±4.57%  ±5.95%
streams/writable-manywrites.jslen=32768 callback='yes' writev='yes' sync='no' n=2000000                 -1.25 %       ±1.98%  ±2.63%  ±3.43%
streams/writable-manywrites.jslen=32768 callback='yes' writev='yes' sync='yes' n=2000000                 0.39 %       ±2.02%  ±2.69%  ±3.51%

Be aware that when doing many comparisons the risk of a false-positive
result increases. In this case, there are 55 comparisons, you can thus
expect the following amount of false-positive results:
  2.75 false positives, when considering a   5% risk acceptance (*, **, ***),
  0.55 false positives, when considering a   1% risk acceptance (**, ***),
  0.06 false positives, when considering a 0.1% risk acceptance (***)

aduh95 avatar Feb 12 '21 22:02 aduh95

regressions regressions

tniessen avatar Feb 16 '21 03:02 tniessen

V8 9.0 update didn't fix the perf regression:

events/ee-once.jsargc=0 n=20000000                               ***    -12.11 %       ±2.77%  ±3.73%  ±4.95%
events/ee-once.jsargc=1 n=20000000                               ***     -8.18 %       ±1.67%  ±2.22%  ±2.89%
events/ee-once.jsargc=4 n=20000000                               ***     -8.07 %       ±2.53%  ±3.37%  ±4.39%
events/ee-once.jsargc=5 n=20000000                               ***     -9.74 %       ±1.74%  ±2.32%  ±3.04%

https://ci.nodejs.org/view/Node.js%20benchmark/job/benchmark-node-micro-benchmarks/962/

aduh95 avatar Mar 15 '21 22:03 aduh95