util: limit inspection output size to 128 MB #22756

BridgeAR · 2018-09-07T20:45:34Z

While working on #19994 after my recent performance improvements
for util.inspect() I took a step back to look at the issue from a different
angle again and I realized that the recursive algorithm is actually the
problem that we ran into in #19405. All parts are put together at the very
end of the computation and no error will be thrown even tough the
maximum string size is long exceeded. Therefore I put together this PR:

The maximum hard limit that util.inspect() could theoretically handle
is the maximum string size. That is ~2 ** 28 on 32 bit systems and
~2 ** 30 on 64 bit systems.

Due to the recursive algorithm a complex object could easily exceed
that limit without throwing an error right away and therefore
crashing the application by exceeding the heap limit.

util.inspect() is fast enough to compute 128 MB in 250 ms on an
Intel(R) Core(TM) i7-5600U CPU. This hard limit allows to inspect arbitrary
big objects from now on without crashing the application or blocking the
event loop significantly.

Checklist

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

nodejs-github-bot · 2018-09-07T20:47:05Z

@BridgeAR sadly an error occured when I tried to trigger a build :(

BridgeAR · 2018-09-08T06:38:58Z

CI https://ci.nodejs.org/job/node-test-pull-request/17082/

vsemozhetbyt · 2018-09-08T09:43:50Z

Nit.

2 ** 30 - 16 on 64 bit systems

2 ** 30 - 25 as of V8 6.2 (quick check: '*'.repeat(2 ** 30 - 25).length vs '*'.repeat(2 ** 30 - 24).length).

vsemozhetbyt · 2018-09-08T09:48:54Z

doc/api/util.md

-intended as a debugging tool. Some input values can have a significant
-performance overhead that can block the event loop. Use this function
-with care and never in a hot code path.
+intended as a debugging tool. It's maximum output length is limited to 128 MB


Nit: It's -> Its

silverwind · 2018-09-08T13:03:31Z

Why not set it to those theoretical limits?

BridgeAR · 2018-09-08T13:16:23Z

@silverwind reaching that limit does not immediately stop the inspection (and we would have to throw an error) but it's normally slightly above - the exact size depends on the shape of the object. On top of that this guarantees that the event loop is not blocked for to long. Increasing the limit to e.g. 756 MB takes more than two seconds on my CPU. I have no strong opinion about it but 128 MB seemed to be a reasonable limit. Passing through a simple string that exceeds that limit is also no problem.

The maximum hard limit that `util.inspect()` could theoretically handle is the maximum string size. That is ~2 ** 28 on 32 bit systems and ~2 ** 30 on 64 bit systems. Due to the recursive algorithm a complex object could easily exceed that limit without throwing an error right away and therefore crashing the application by exceeding the heap limit. `util.inspect()` is fast enough to compute 128 MB of data below one second on an Intel(R) Core(TM) i7-5600U CPU. This hard limit allows to inspect arbitrary big objects from now on without crashing the application or blocking the event loop significantly.

silverwind · 2018-09-09T06:09:43Z

@BridgeAR I see. Maybe we should do 128MB on 32 bit and 512MB on 64 bit? Would be approximately half of the theoretical limit. Of course this wouldn't be so great for portability, so if you want to keep it at 128MB, that's fine too.

silverwind · 2018-09-09T06:12:32Z

If it's going to be different limits, I think we should expose it as a constant, e.g. util.MAX_SAFE_INSPECT_SIZE or similar.

BridgeAR · 2018-09-09T23:33:12Z

@silverwind I thought about doing exactly what you suggest but I personally prefer to have the same cap, especially as it limits the time to inspect an object to a reasonable level. Inspecting an object that produces 512 MB output blocks the event loop for quite some time, even on good hardware.

Normally exposing a constant for things like that is something I would very much agree with but in this case I am not sure about the benefit for the user as there's probably little the user could do in such situations. Knowing when inspecting the value exceeds the output limit will be hard up front.

We could add a special text for the not fully inspected part to make sure the user actually notices it properly (even tough that might be repeated relatively often in the output).

BridgeAR · 2018-09-10T07:51:09Z

@nodejs/tsc PTAL

mcollina

LGTM with a nit

mcollina · 2018-09-10T08:03:59Z

lib/util.js

+  const budget = ctx.budget[ctx.indentationLvl] || 0;
+  const newLength = budget + res.length;
+  ctx.budget[ctx.indentationLvl] = newLength;
+  if (newLength > 2 ** 27) {


can you add a comment here?

jasnell · 2018-09-10T17:02:46Z

Definitely would need a CITGM run and verification that this does not break npmlog

BridgeAR · 2018-09-11T14:49:40Z

~~CITGM https://ci.nodejs.org/view/Node.js-citgm/job/citgm-smoker/1540/~~
CITGM https://ci.nodejs.org/view/Node.js-citgm/job/citgm-smoker/1541/

BridgeAR · 2018-09-11T20:49:40Z

CI https://ci.nodejs.org/job/node-test-pull-request/17119/

vsemozhetbyt · 2018-09-11T20:52:53Z

lib/util.js

+  // If any indentationLvl exceeds this limit, limit further inspecting to the
+  // minimum. Otherwise the recursive algorithm might continue inspecting the
+  // object even tough the maximum string size (~2 ** 28 on 32 bit systems and
+  // ~2 ** 64) exceeded. The actual output is not limited at exactly 2 ** 27 but


~2 ** 64 -> ~2 ** 30 on 64 bit systems?

vsemozhetbyt · 2018-09-11T20:54:39Z

lib/util.js

@@ -897,6 +897,13 @@ function formatRaw(ctx, value, recurseTimes) {
  const budget = ctx.budget[ctx.indentationLvl] || 0;
  const newLength = budget + res.length;
  ctx.budget[ctx.indentationLvl] = newLength;
+  // If any indentationLvl exceeds this limit, limit further inspecting to the
+  // minimum. Otherwise the recursive algorithm might continue inspecting the
+  // object even tough the maximum string size (~2 ** 28 on 32 bit systems and


tough -> though

BridgeAR · 2018-09-11T21:43:01Z

CI https://ci.nodejs.org/job/node-test-pull-request/17121/

addaleax · 2018-09-12T11:10:47Z

doc/api/util.md

+  - version: REPLACEME
+    pr-url: https://github.com/nodejs/node/pull/REPLACEME
+    description: The inspection output is now limited to 128 MB. Data above that
+                 size not be inspected fully anymore.


I think this is missing a verb? 😄

lib/util.js

jdalton · 2018-09-12T15:31:52Z

doc/api/util.md

-performance overhead that can block the event loop. Use this function
-with care and never in a hot code path.
+intended as a debugging tool. Its maximum output length is limited to 128 MB and
+input values that result in output bigger than that will not be inspected fully.


☝️ Since this is a heuristic is it approximately 128 mb or exactly?

It should be detected by the very first entry that exceeds that limit (but only after being fully inspected at that level).

And that is also not exact as the higher levels could already contain data that will be added on top of that. It is fairly precise if the individual properties on the object are not that big. If each of them is huge, the limit will not be as exact.

Could the wording be tweaked to qualify it as "approximately 128 MB"?

jdalton · 2018-09-12T15:32:04Z

lib/util.js

+  if (newLength > 2 ** 27) {
+    ctx.stop = true;
+  }
+  return res;
 }


I get wanting to limit string construction to avoid memory issues and it looks like when this is implemented objects just won't be crawled (something like "[Object]") which are both good.

Am I correct that the indentation level is just a hint that there could be a possible problem (it's unknown until the objects are crawled and inspected) and so it's being defensive and not going further?

Can indentation level be translated to depth?
(I think depth would be easier to reason about at a glance than indenting)

Can an object still be created that busts this heuristic?

Yes, it's unknown until we crawled and inspected the object and after exceeding the limit it's continuing defensively.

Yes, that is possible. Using depth is not possible though, as it's value is set by the user (e.g., to Infinity), not by inspect() itself. indentationLvl is only meant to be internal and is never set to Infinity.

That would be possible. E.g., util.inspect(new Uint8Array(1e8), { maxArrayLength: Infinity }). If an individual part of an object exceeds the limit on it's own or the total space left, it's not going to protect against it.

Looking at this again: the depth and the indentationLvl would be great to be combined but the compact: true mode has different indention for different values. That's why it's currently not possible :/

That's cool. This is a good first attempt at least.

BridgeAR · 2018-09-12T22:06:03Z

Comments addressed.

CI https://ci.nodejs.org/job/node-test-pull-request/17157/

BridgeAR · 2018-09-13T08:50:45Z

Landed in eb61127 🎉

The maximum hard limit that `util.inspect()` could theoretically handle is the maximum string size. That is ~2 ** 28 on 32 bit systems and ~2 ** 30 on 64 bit systems. Due to the recursive algorithm a complex object could easily exceed that limit without throwing an error right away and therefore crashing the application by exceeding the heap limit. `util.inspect()` is fast enough to compute 128 MB of data below one second on an Intel(R) Core(TM) i7-5600U CPU. This hard limit allows to inspect arbitrary big objects from now on without crashing the application or blocking the event loop significantly. PR-URL: nodejs#22756 Reviewed-By: Matteo Collina <matteo.collina@gmail.com> Reviewed-By: James M Snell <jasnell@gmail.com> Reviewed-By: Anna Henningsen <anna@addaleax.net> Reviewed-By: John-David Dalton <john.david.dalton@gmail.com>

Notable changes: * Build * FreeBSD 10 is no longer supported. [#22617](#22617) * `child_process` * The default value of the `windowsHide` option has been changed to `true`. [#21316](#21316) * `console` * `console.countReset()` will emit a warning if the timer being reset does not exist. [#21649](#21649) * `console.time()` will no longer reset a timer if it already exists. [#20442](#20442) * `crypto` * PEM-level encryption is now supported. [#23151](#23151) * An API for key pair generation has been added. [#22660](#22660) * Dependencies * V8 has been updated to 7.0. [#22754](#22754) * `fs` * The `fs.read()` method now requires a callback. [#22146](#22146) * The previously deprecated `fs.SyncWriteStream` utility has been removed.[#20735](#20735) * `http` * The `http`, `https`, and `tls` modules now use the WHATWG URL parser by default. [#20270](#20270) * `http2` * An event will be emitted when a `PING` frame is received. [#23009](#23009) * Support for the `ORIGIN` frame has been added. [#22956](#22956) * General * Use of `process.binding()` has been deprecated. Userland code using `process.binding()` should re-evaluate that use and begin migrating. * An experimental implementation of `queueMicrotask()` has been added. [#22951](#22951) * Internal * Windows performance-counter support has been removed. [#22485](#22485) * The `--expose-http2` command-line option has been removed. [#20887](#20887) * Promises * A new `multipleResolves` event will be emitted when a Promise is resolved (or rejected) more than once. [#22218](#22218) * Timers * Interval timers will be rescheduled even if previous interval threw an error. [#20002](#20002) * `util` * The WHATWG `TextEncoder` and `TextDecoder` are now globals. [#22281](#22281) * `util.inspect()` output size is limited to 128 MB by default. [#22756](#22756) * A runtime warning will be emitted when `NODE_DEBUG` is set for either `http` or `http2`. [#21914](#21914)

Notable changes: * Build * FreeBSD 10 is no longer supported.[#22617](#22617) * `child_process` * The default value of the `windowsHide` option has been changed to `true`. [#21316](#21316) * `console` * `console.countReset()` will emit a warning if the timer being reset does not exist. [#21649](#21649) * `console.time()` will no longer reset a timer if it already exists. [#20442](#20442) * Dependencies * V8 has been updated to 7.0. [#22754](#22754) * `fs` * The `fs.read()` method now requires a callback. [#22146](#22146) * The previously deprecated `fs.SyncWriteStream` utility has been removed.[#20735](#20735) * `http` * The `http`, `https`, and `tls` modules now use the WHATWG URL parser by default. [#20270](#20270) * General * Use of `process.binding()` has been deprecated. Userland code using `process.binding()` should re-evaluate that use and begin migrating. If there are no supported API alternatives, please open an issue in the Node.js GitHub repository so that a suitable alternative may be discussed. * An experimental implementation of `queueMicrotask()` has been added. [#22951](#22951) * Internal * Windows performance-counter support has been removed. [#22485](#22485) * The `--expose-http2` command-line option has been removed. [#20887](#20887) * Timers * Interval timers will be rescheduled even if previous interval threw an error. [#20002](#20002) * `util` * The WHATWG `TextEncoder` and `TextDecoder` are now globals. [#22281](#22281) * `util.inspect()` output size is limited to 128 MB by default. [#22756](#22756) * A runtime warning will be emitted when `NODE_DEBUG` is set for either `http` or `http2`. [#21914](#21914)

Notable changes: * Build * FreeBSD 10 is no longer supported.[nodejs#22617](nodejs#22617) * `child_process` * The default value of the `windowsHide` option has been changed to `true`. [nodejs#21316](nodejs#21316) * `console` * `console.countReset()` will emit a warning if the timer being reset does not exist. [nodejs#21649](nodejs#21649) * `console.time()` will no longer reset a timer if it already exists. [nodejs#20442](nodejs#20442) * Dependencies * V8 has been updated to 7.0. [nodejs#22754](nodejs#22754) * `fs` * The `fs.read()` method now requires a callback. [nodejs#22146](nodejs#22146) * The previously deprecated `fs.SyncWriteStream` utility has been removed.[nodejs#20735](nodejs#20735) * `http` * The `http`, `https`, and `tls` modules now use the WHATWG URL parser by default. [nodejs#20270](nodejs#20270) * General * Use of `process.binding()` has been deprecated. Userland code using `process.binding()` should re-evaluate that use and begin migrating. If there are no supported API alternatives, please open an issue in the Node.js GitHub repository so that a suitable alternative may be discussed. * An experimental implementation of `queueMicrotask()` has been added. [nodejs#22951](nodejs#22951) * Internal * Windows performance-counter support has been removed. [nodejs#22485](nodejs#22485) * The `--expose-http2` command-line option has been removed. [nodejs#20887](nodejs#20887) * Timers * Interval timers will be rescheduled even if previous interval threw an error. [nodejs#20002](nodejs#20002) * `util` * The WHATWG `TextEncoder` and `TextDecoder` are now globals. [nodejs#22281](nodejs#22281) * `util.inspect()` output size is limited to 128 MB by default. [nodejs#22756](nodejs#22756) * A runtime warning will be emitted when `NODE_DEBUG` is set for either `http` or `http2`. [nodejs#21914](nodejs#21914)

Notable changes: * Build * FreeBSD 10 is no longer supported.[#22617](nodejs/node#22617) * `child_process` * The default value of the `windowsHide` option has been changed to `true`. [#21316](nodejs/node#21316) * `console` * `console.countReset()` will emit a warning if the timer being reset does not exist. [#21649](nodejs/node#21649) * `console.time()` will no longer reset a timer if it already exists. [#20442](nodejs/node#20442) * Dependencies * V8 has been updated to 7.0. [#22754](nodejs/node#22754) * `fs` * The `fs.read()` method now requires a callback. [#22146](nodejs/node#22146) * The previously deprecated `fs.SyncWriteStream` utility has been removed.[#20735](nodejs/node#20735) * `http` * The `http`, `https`, and `tls` modules now use the WHATWG URL parser by default. [#20270](nodejs/node#20270) * General * Use of `process.binding()` has been deprecated. Userland code using `process.binding()` should re-evaluate that use and begin migrating. If there are no supported API alternatives, please open an issue in the Node.js GitHub repository so that a suitable alternative may be discussed. * An experimental implementation of `queueMicrotask()` has been added. [#22951](nodejs/node#22951) * Internal * Windows performance-counter support has been removed. [#22485](nodejs/node#22485) * The `--expose-http2` command-line option has been removed. [#20887](nodejs/node#20887) * Timers * Interval timers will be rescheduled even if previous interval threw an error. [#20002](nodejs/node#20002) * `util` * The WHATWG `TextEncoder` and `TextDecoder` are now globals. [#22281](nodejs/node#22281) * `util.inspect()` output size is limited to 128 MB by default. [#22756](nodejs/node#22756) * A runtime warning will be emitted when `NODE_DEBUG` is set for either `http` or `http2`. [#21914](nodejs/node#21914)

BridgeAR requested a review from addaleax September 7, 2018 20:45

nodejs-github-bot added the util Issues and PRs related to the built-in util module. label Sep 7, 2018

BridgeAR force-pushed the limit-inspection-size branch from 633ba62 to e8f02b4 Compare September 7, 2018 20:46

vsemozhetbyt reviewed Sep 8, 2018

View reviewed changes

BridgeAR added 2 commits September 8, 2018 16:53

fixup: address comment

8742df1

BridgeAR force-pushed the limit-inspection-size branch from e8f02b4 to 8742df1 Compare September 8, 2018 14:54

BridgeAR added the semver-major PRs that contain breaking changes and should be released in the next major version. label Sep 10, 2018

BridgeAR requested review from a team and removed request for a team September 10, 2018 07:49

mcollina approved these changes Sep 10, 2018

View reviewed changes

jasnell approved these changes Sep 10, 2018

View reviewed changes

fixup: add comment

b1cb015

BridgeAR added the author ready PRs that have at least one approval, no pending requests for changes, and a CI started. label Sep 11, 2018

vsemozhetbyt reviewed Sep 11, 2018

View reviewed changes

fixup: address comment

e133551

addaleax reviewed Sep 12, 2018

View reviewed changes

addaleax approved these changes Sep 12, 2018

View reviewed changes

jdalton reviewed Sep 12, 2018

View reviewed changes

fixup: address comments in util.md

0dde647

BridgeAR force-pushed the limit-inspection-size branch from 560e896 to 0dde647 Compare September 12, 2018 22:03

BridgeAR mentioned this pull request Sep 12, 2018

util: add computeTime option to inspect #19994

Closed

4 tasks

jdalton approved these changes Sep 12, 2018

View reviewed changes

BridgeAR closed this Sep 13, 2018

jasnell mentioned this pull request Oct 2, 2018

11.0.0 proposal #23230

Closed

4 tasks

BridgeAR deleted the limit-inspection-size branch January 20, 2020 11:38

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

util: limit inspection output size to 128 MB #22756

util: limit inspection output size to 128 MB #22756

BridgeAR commented Sep 7, 2018 •

edited

Loading

nodejs-github-bot commented Sep 7, 2018

BridgeAR commented Sep 8, 2018

vsemozhetbyt commented Sep 8, 2018 •

edited

Loading

vsemozhetbyt Sep 8, 2018

silverwind commented Sep 8, 2018

BridgeAR commented Sep 8, 2018 •

edited

Loading

silverwind commented Sep 9, 2018 •

edited

Loading

silverwind commented Sep 9, 2018

BridgeAR commented Sep 9, 2018

BridgeAR commented Sep 10, 2018

mcollina left a comment

mcollina Sep 10, 2018

jasnell commented Sep 10, 2018

BridgeAR commented Sep 11, 2018 •

edited

Loading

BridgeAR commented Sep 11, 2018

vsemozhetbyt Sep 11, 2018

vsemozhetbyt Sep 11, 2018

BridgeAR commented Sep 11, 2018

addaleax Sep 12, 2018

jdalton Sep 12, 2018

BridgeAR Sep 12, 2018

BridgeAR Sep 12, 2018

jdalton Sep 12, 2018

jdalton Sep 12, 2018

BridgeAR Sep 12, 2018 •

edited

Loading

BridgeAR Sep 12, 2018

jdalton Sep 12, 2018

BridgeAR commented Sep 12, 2018

BridgeAR commented Sep 13, 2018

util: limit inspection output size to 128 MB #22756

util: limit inspection output size to 128 MB #22756

Conversation

BridgeAR commented Sep 7, 2018 • edited Loading

Checklist

nodejs-github-bot commented Sep 7, 2018

BridgeAR commented Sep 8, 2018

vsemozhetbyt commented Sep 8, 2018 • edited Loading

Choose a reason for hiding this comment

silverwind commented Sep 8, 2018

BridgeAR commented Sep 8, 2018 • edited Loading

silverwind commented Sep 9, 2018 • edited Loading

silverwind commented Sep 9, 2018

BridgeAR commented Sep 9, 2018

BridgeAR commented Sep 10, 2018

mcollina left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

jasnell commented Sep 10, 2018

BridgeAR commented Sep 11, 2018 • edited Loading

BridgeAR commented Sep 11, 2018

Choose a reason for hiding this comment

Choose a reason for hiding this comment

BridgeAR commented Sep 11, 2018

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

BridgeAR Sep 12, 2018 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

BridgeAR commented Sep 12, 2018

BridgeAR commented Sep 13, 2018

BridgeAR commented Sep 7, 2018 •

edited

Loading

vsemozhetbyt commented Sep 8, 2018 •

edited

Loading

BridgeAR commented Sep 8, 2018 •

edited

Loading

silverwind commented Sep 9, 2018 •

edited

Loading

BridgeAR commented Sep 11, 2018 •

edited

Loading

BridgeAR Sep 12, 2018 •

edited

Loading