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

util.inspect({level: "info"}) exits the debug session #4440

Closed
learnerbyheart opened this issue Dec 27, 2015 · 43 comments
Closed

util.inspect({level: "info"}) exits the debug session #4440

learnerbyheart opened this issue Dec 27, 2015 · 43 comments
Labels
util Issues and PRs related to the built-in util module.

Comments

@learnerbyheart
Copy link

When debugging in node.js 5.3.0 the script bug.js

var util = require('util');
util.inspect({level: "info "});
console.log("Test");

with node debug bug.js, the debugging session exits. I tried the same in node.js 4.2.4 and it doesn't. When debugging the difference in lib/util.js, line 324 in 5.3.0 looks like this:

var promiseInternals = inspectPromise(value);

and line 319 in 4.2.4 looks like:

var promiseInternals = value instanceof Promise && inspectPromise(value);

As value is not an instance of Promise, inspectPromise(value) is called in 5.3.0. Then inspectPromise calls ensureDebugIsInitialized() which on the other hand calls require('vm').runInDebugContext('Debug'). This causes the debugging session to exit. The issue was tested in Ubuntu 14.04 LTS.

@mscdex mscdex added the util Issues and PRs related to the built-in util module. label Dec 27, 2015
@mscdex
Copy link
Contributor

mscdex commented Dec 27, 2015

Can you clarify what you're doing step-by-step? You mention running that script with node debug but where does the util.inspect({level: 'info'}) come into play? I ran the script as you say, it breaks on the first statement and continuing execution at the debug> prompt results in "Finished" logged to stdout as expected.

@learnerbyheart
Copy link
Author

Sorry, that was an copy and paste fault by me. I updated my initial comment where the right bug.js script is described.

@learnerbyheart
Copy link
Author

But the before mentioned script bug2.js

var vm = require('vm');
vm.runInDebugContext('Debug');
console.log("Finished");

exits after vm.runInDebugContext('Debug'); when I run node debug bug2.js.

@mscdex
Copy link
Contributor

mscdex commented Dec 27, 2015

I'm not able to reproduce that on master:

$ cat bug.js 
var vm = require('vm');
vm.runInDebugContext('Debug');
console.log("Finished");
$ ./node debug bug.js
< Debugger listening on port 5858
connecting to 127.0.0.1:5858 ... ok
break in bug.js:1
> 1 var vm = require('vm');
  2 vm.runInDebugContext('Debug');
  3 console.log("Finished");
debug> c
< Finished
debug> .exit

@mscdex
Copy link
Contributor

mscdex commented Dec 27, 2015

Similarly with your updated code example, I cannot reproduce the problem there either on master:

$ cat bug2.js 
var util = require('util');
util.inspect({level: "info "});
console.log("Test");
$ ./node debug bug2
< Debugger listening on port 5858
connecting to 127.0.0.1:5858 ... ok
break in bug2.js:1
> 1 var util = require('util');
  2 util.inspect({level: "info "});
  3 console.log("Test");
debug> c
< Test
debug> .exit

@mscdex
Copy link
Contributor

mscdex commented Dec 27, 2015

Perhaps there's something that needs to be backported to 5.x yet?

@learnerbyheart
Copy link
Author

I debugged the script

var vm = require('vm');
vm.runInDebugContext('Debug');
console.log("Finished");

in a new workspace in cloud9 (https://c9.io/) which has node 4.1.1 and Ubuntu 14.04 LTS, on my private Laptop which has node 5.3.0 and Ubuntu 15.10 and on a new VM with a fresh Ubuntu 14.04 LTS and node 4.2.4. In every environment the debugging exits after vm.runInDebugContext('Debug');. Usually I code in WebStorm which exited with exit code 139 when debugging it. When debugging it via node-inspector as well with cloud9 the error message was a segmentation fault.
Does it has something to do with Ubuntu as the operating system? Which os did you use? Does the master branch differs from the 5.3.0 tag?

@mscdex
Copy link
Contributor

mscdex commented Dec 27, 2015

Yes, master represents the next major version. Necessary commits are backported to versioned branches (e.g. v4.x, v5.x, etc.).

It shouldn't be OS-related. I don't know offhand what needs to be backported, there's a fair amount of different stuff in master (including a new "major" v8 version).

@Trott
Copy link
Member

Trott commented Dec 27, 2015

On OSX, it's broken for me in Node 5.3.0 but works fine with current master.

5.3.0:

$ cat test.js
var vm = require('vm');
vm.runInDebugContext('Debug');
console.log("Finished");
$ node debug test.js 
< Debugger listening on port 5858
connecting to 127.0.0.1:5858 ... ok
break in test.js:1
> 1 var vm = require('vm');
  2 vm.runInDebugContext('Debug');
  3 console.log("Finished");
debug> c
program terminated
debug> .exit

master:

$ ~/io.js/node debug test.js 
< Debugger listening on port 5858
connecting to 127.0.0.1:5858 ... ok
break in test.js:1
> 1 var vm = require('vm');
  2 vm.runInDebugContext('Debug');
  3 console.log("Finished");
debug> c
< Finished
debug> .exit

@Trott
Copy link
Member

Trott commented Dec 27, 2015

Maybe it was fixed by 25776f3?

@bnoordhuis
Copy link
Member

25776f3 is almost certainly the fix. (EDIT: And hasn't been released yet.)

@learnerbyheart
Copy link
Author

In which release will it be inculded? 5.4.0? When will this release be published?

@Trott
Copy link
Member

Trott commented Dec 29, 2015

@LucasMoody It should be in the next release which will either be 5.3.1 or 5.4.0 depending on what else is in the release.

For the stable release line (currently 5.x), the goal is to have a release every 1-2 weeks. The release team seems to be meeting that goal. There's probably not much activity this week, though, as it's a major holiday in much of the world. So add one more week maybe.

So, the unofficial upshot from my non-release-team-member analysis would be: A release with the fix should be out by January 15, and probably sooner.

@cjihrig
Copy link
Contributor

cjihrig commented Dec 29, 2015

I'm going to close this as it appears to be fixed in master. As @Trott mentioned, a new release should be out soon - almost certainly before January 15.

@cjihrig cjihrig closed this as completed Dec 29, 2015
@learnerbyheart
Copy link
Author

Hey, after I cloned the Master branch and installed node, I debugged the following util-bug.js script:

var util = require('util');
util.inspect({level: "info"});
1 + 1;
2 + 2;
console.log("Finished");

After setting a breakpoint in line 4 with sb(4) and entering c the debugger doesn't show the source code anymore, even if I type list(5). After typing list(5) the debugger frozes. As described in my first post, I guess node.inspect executes vm.runInDebugContext('Debug'). I'm not quite sure what vm.runInDebugContext does, but after executing the line in debug mode, I cannot debug further (continue to breakpoints, list source code, etc.). Could you please reopen the issue and take a look at this.
Best regards,
Lucas

@Trott
Copy link
Member

Trott commented Jan 1, 2016

Re-opening as requested. If someone else feels like this ought to remain closed and a new issue opened instead, feel free to close and comment to that effect. It does seem like this is a new issue that was masked by the first issue.

@Trott Trott reopened this Jan 1, 2016
@atom0s
Copy link

atom0s commented Jan 6, 2016

I see this issue happening while using 5.3.0 with this node module: https://github.com/Azure/azure-storage-node

While checking for a container on Azure, the module will call:

self.logger.log(Logger.LogLevels.DEBUG, 'FINAL REQUEST OPTIONS:\n' + util.inspect(finalRequestOptions));

Which results in a crash at the same location that @LucasMoody mentioned. It will eventually get down to:
util.js

var promiseInternals = inspectPromise(value);

And crash here:
vm.js

exports.runInDebugContext = function(code) {
    return binding.runInDebugContext(code);
};

If it helps with debugging this problem, the logger that azure sets up in that module is done like this:

var Logger = require('../diagnostics/logger');
this.logger = new Logger(Logger.LogLevels.INFO);

Their logger can be seen here:
https://github.com/Azure/azure-storage-node/blob/master/lib/common/diagnostics/logger.js

@cohowap
Copy link

cohowap commented Jan 12, 2016

This does seem to still exist on Node 5.4.0. I am seeing exactly what @atom0s is seeing.

@learnerbyheart
Copy link
Author

Hey @mscdex and @Trott,
is there any update on this issue? There has not been any messages for 2 weeks.

@Trott
Copy link
Member

Trott commented Jan 14, 2016

I don't know that anyone is actively working on this issue. (If someone is, hey, speak up here, will ya?)

I'm not sure who the key contacts would be for the debugger, but judging from the commit logs, I'd guess @indutny. Not sure if he has sufficient spare time and inclination to dive into this issue, but if not, maybe he can at least point someone in the right general direction.

If you're feeling like you might want to take a shot at solving the problem yourself, then (absent suggestions from other people who are more informed than I am) I'd start by looking at these files in the source code repo:

lib/_debug_agent.js
lib/_debugger.js
src/debug-agent.cc
src/debug-agent.h

Hopefully @mscdex or someone else will have something more helpful to offer, but for the moment, that's what I've got.

@mscdex
Copy link
Contributor

mscdex commented Jan 14, 2016

I have no idea either offhand what the change was. You could git bisect it I suppose.

@daef
Copy link

daef commented Jan 20, 2016

i'm experiencing this issue when debugging my expressjs application via node-debug (node 5.4.1)

express logs a value, the formatter tries to inspect the value via inspectPromise, which calls ensureDebugIsInitialized and my debugging session is gone

any workarounds?

@AdamAndersonFalafelSoftware

I also experienced this problem on Windows 10. Downgrading to Node 4.2.4 (and then installing the latest NPM to avoid MAX_PATH issues) worked around the issue for me.

@MylesBorins
Copy link
Contributor

I bet this is the same problem we are seeing in #4815

@jasnell
Copy link
Member

jasnell commented Jan 23, 2016

From what I've been able to investigate @thealphanerd ... I tend to agree.

@guidoman
Copy link

guidoman commented Feb 5, 2016

Similar behavior described by @imaustink with Webstorm under OS X with 4.2.6. Node 4.2.2 is working OK.

@MylesBorins
Copy link
Contributor

There is a fix in, hoping to have it released for ya'll soon after the next security release

#4819

@mikermcneil
Copy link

Thanks @thealphanerd!

In the mean time, for folks stumbling upon this, I can confirm that downgrading to 4.2.4 resolves this for folks seeing issues in their Sails apps (thanks @chirag200666 and @LongSteve!)

@MylesBorins
Copy link
Contributor

The fix is now in master, you should expect this to see it in a release in the next 2 - 3 weeks on v4 and v5.

@atom0s
Copy link

atom0s commented Feb 6, 2016

Thanks for your efforts @thealphanerd it is greatly appreciated.

rvagg pushed a commit that referenced this issue Feb 8, 2016
Currently a debug context is created for various calls to util.

If the node debugger is being run the main context is the debug
context. In this case node_contextify was freeing the debug context
and causing everything to explode.

This change moves around the logic and no longer frees the context.

There is a concern about the dangling pointer

The regression test was adapted from code submitted by @3y3 in #4815

Fixes: #4440
Fixes: #4815
Fixes: #4597
Fixes: #4952

PR-URL: #4815

Reviewed-By: Fedor Indutny <fedor.indutny@gmail.com>
Reviewed-By: Ben Noordhuis <info@bnoordhuis.nl>
Reviewed-By: Rich Trott <rtrott@gmail.com>
rvagg pushed a commit that referenced this issue Feb 9, 2016
Currently a debug context is created for various calls to util.

If the node debugger is being run the main context is the debug
context. In this case node_contextify was freeing the debug context
and causing everything to explode.

This change moves around the logic and no longer frees the context.

There is a concern about the dangling pointer

The regression test was adapted from code submitted by @3y3 in #4815

Fixes: #4440
Fixes: #4815
Fixes: #4597
Fixes: #4952

PR-URL: #4815

Reviewed-By: Fedor Indutny <fedor.indutny@gmail.com>
Reviewed-By: Ben Noordhuis <info@bnoordhuis.nl>
Reviewed-By: Rich Trott <rtrott@gmail.com>
@MylesBorins
Copy link
Contributor

The fix is now released in v5.6.0. Expect LTS next week

@Smurf-IV
Copy link

Still broken in 4.3.0
with the following code in WebStorm 11.03 debug

        var jsonData = jsonfile.readFileSync(fromFile);
        log.trace(jsonData);

The trace (or info levels etc) is dumped, but the debug session is exited afterwards.

@atom0s
Copy link

atom0s commented Feb 11, 2016

The comment just above yours mentioned already that it will be fixed at a later time for LTS.

@jasnell
Copy link
Member

jasnell commented Feb 11, 2016

Yes, v4.3.0 was a security fix that only included the fixes for the
security issues. It bumped all other fixes to the next LTS release which
we'll be working on soon.
On Feb 11, 2016 1:35 AM, "atom0s" notifications@github.com wrote:

The comment just above yours mentioned already that it will be fixed at a
later time for LTS.


Reply to this email directly or view it on GitHub
#4440 (comment).

MylesBorins pushed a commit that referenced this issue Feb 11, 2016
Currently a debug context is created for various calls to util.

If the node debugger is being run the main context is the debug
context. In this case node_contextify was freeing the debug context
and causing everything to explode.

This change moves around the logic and no longer frees the context.

There is a concern about the dangling pointer

The regression test was adapted from code submitted by @3y3 in #4815

Fixes: #4440
Fixes: #4815
Fixes: #4597
Fixes: #4952

PR-URL: #4815

Reviewed-By: Fedor Indutny <fedor.indutny@gmail.com>
Reviewed-By: Ben Noordhuis <info@bnoordhuis.nl>
Reviewed-By: Rich Trott <rtrott@gmail.com>
MylesBorins pushed a commit to MylesBorins/node that referenced this issue Feb 11, 2016
Currently a debug context is created for various calls to util.

If the node debugger is being run the main context is the debug
context. In this case node_contextify was freeing the debug context
and causing everything to explode.

This change moves around the logic and no longer frees the context.

There is a concern about the dangling pointer

The regression test was adapted from code submitted by @3y3 in nodejs#4815

Fixes: nodejs#4440
Fixes: nodejs#4815
Fixes: nodejs#4597
Fixes: nodejs#4952

PR-URL: nodejs#4815

Reviewed-By: Fedor Indutny <fedor.indutny@gmail.com>
Reviewed-By: Ben Noordhuis <info@bnoordhuis.nl>
Reviewed-By: Rich Trott <rtrott@gmail.com>
MylesBorins pushed a commit to MylesBorins/node that referenced this issue Feb 13, 2016
Currently a debug context is created for various calls to util.

If the node debugger is being run the main context is the debug
context. In this case node_contextify was freeing the debug context
and causing everything to explode.

This change moves around the logic and no longer frees the context.

There is a concern about the dangling pointer

The regression test was adapted from code submitted by @3y3 in nodejs#4815

Fixes: nodejs#4440
Fixes: nodejs#4815
Fixes: nodejs#4597
Fixes: nodejs#4952

PR-URL: nodejs#4815

Reviewed-By: Fedor Indutny <fedor.indutny@gmail.com>
Reviewed-By: Ben Noordhuis <info@bnoordhuis.nl>
Reviewed-By: Rich Trott <rtrott@gmail.com>
MylesBorins pushed a commit to MylesBorins/node that referenced this issue Feb 15, 2016
Currently a debug context is created for various calls to util.

If the node debugger is being run the main context is the debug
context. In this case node_contextify was freeing the debug context
and causing everything to explode.

This change moves around the logic and no longer frees the context.

There is a concern about the dangling pointer

The regression test was adapted from code submitted by @3y3 in nodejs#4815

Fixes: nodejs#4440
Fixes: nodejs#4815
Fixes: nodejs#4597
Fixes: nodejs#4952

PR-URL: nodejs#4815

Reviewed-By: Fedor Indutny <fedor.indutny@gmail.com>
Reviewed-By: Ben Noordhuis <info@bnoordhuis.nl>
Reviewed-By: Rich Trott <rtrott@gmail.com>
@rainabba
Copy link
Contributor

This isn't TOP priority? #4382

@MylesBorins
Copy link
Contributor

As mentioned above 4.3.1 has been released with the fix for this bug!

scovetta pushed a commit to scovetta/node that referenced this issue Apr 2, 2016
Currently a debug context is created for various calls to util.

If the node debugger is being run the main context is the debug
context. In this case node_contextify was freeing the debug context
and causing everything to explode.

This change moves around the logic and no longer frees the context.

There is a concern about the dangling pointer

The regression test was adapted from code submitted by @3y3 in nodejs#4815

Fixes: nodejs#4440
Fixes: nodejs#4815
Fixes: nodejs#4597
Fixes: nodejs#4952

PR-URL: nodejs#4815

Reviewed-By: Fedor Indutny <fedor.indutny@gmail.com>
Reviewed-By: Ben Noordhuis <info@bnoordhuis.nl>
Reviewed-By: Rich Trott <rtrott@gmail.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
util Issues and PRs related to the built-in util module.
Projects
None yet
Development

No branches or pull requests