Skip to content

Instantly share code, notes, and snippets.

@misterdjules
Last active August 29, 2015 14:08
Show Gist options
  • Save misterdjules/c37c927509474df762c0 to your computer and use it in GitHub Desktop.
Save misterdjules/c37c927509474df762c0 to your computer and use it in GitHub Desktop.
Feedback after testing the new mdb-v8 in https://github.com/davepacheco/node/tree/dap-mdb

Tests results

64 bits - master

node-debug-school

Works fine!

test-postmortem-findjsobjects.js

Passes.

test-postmortem-jsstack.js
[root@f48db5f2-4c15-4b78-ba03-ae253f045446 ~/node]# ./node test/pummel/test-postmortem-jsstack.js 
mdb stderr: mdb: for script 28b719a3ec09, could not determine startline/endline (start 5121, end 6477, nlines 5): no symbol corresponds to address

mdb stderr: mdb: for script 28b719a3ec09, could not determine startline/endline (start 5121, end 6761, nlines 5): no symbol corresponds to address
mdb: for script 28b719a3ec09, could not determine startline/endline (start 5121, end 7277, nlines 5): no symbol corresponds to address
mdb: for script 28b719a4a199, could not determine startline/endline (start 28673, end 12420, nlines 5): no symbol corresponds to address

[root@f48db5f2-4c15-4b78-ba03-ae253f045446 ~/node]# echo $?
0
[root@f48db5f2-4c15-4b78-ba03-ae253f045446 ~/node]#

The test seems to pass, but I'm not sure about mdb's err output.

test-postmortem-details.js
  • Some tests seem to fail because of tabs in mdb's output, the following changes fix the problem:
diff --git a/test/pummel/test-postmortem-details.js b/test/pummel/test-postmortem-details.js
index 825952b..5eda6db 100644
--- a/test/pummel/test-postmortem-details.js
+++ b/test/pummel/test-postmortem-details.js
@@ -147,7 +147,8 @@ gcore.on('exit', function (code) {
   });
   verifiers.push(function verifyJsfunctionN(testlines) {
     assert.equal(testlines.length, 2);
-    var parts = testlines[1].split(/\s+/);
+    var parts = testlines[1].trim().split(/\s+/);
+    console.log('parts:', parts);
     assert.equal(parts[1], 1);
     assert.equal(parts[2], 'myTestFunction');
     assert.ok(parts[3].indexOf('test-postmortem-details.js') != -1);
@@ -156,7 +157,7 @@ gcore.on('exit', function (code) {
     var foundtest = false, founditer = false;
     assert.ok(testlines.length > 1);
     testlines.forEach(function (line) {
-      var parts = line.split(/\s+/);
+      var parts = line.trim().split(/\s+/);
       if (parts[2] == 'myIterFunction') {
         assert.equal(parts[1], '3');
         founditer = true;
  • The test for the ::jssource command seems to fail. Here's the output from mdb after loading the core file generated by the test:
> ::jsfunctions -n myTestFunction ! awk 'NR == 2 {print $1}' | head -1 
2630ab08eeb1
> 2630ab08eeb1::jssource -n 0
file: /root/node/test/pummel/test-postmortem-details.js

  137     assert.equal(testlines.length, 1);
  138     assert.ok(/^[0-9a-fA-F]+$/.test(testlines[0]));
  139     buffer = testlines[0];
  140   });
  141   verifiers.push(function verifyBufferContents(testlines) {
  142     assert.equal(testlines.length, 1);
  143     assert.equal(testlines[0], '0x' + buffer + ':      Hello');
  144   });
  145   verifiers.push(function verifyV8internal(testlines) {
  146     assert.deepEqual(testlines, [ buffer ]);
  147   });
  148   verifiers.push(function verifyJsfunctionN(testlines) {
  149     assert.equal(testlines.length, 2);
  150     var parts = testlines[1].split(/\s+/);
  151     assert.equal(parts[1], 1);
  152     assert.equal(parts[2], 'myTestFunction');
  153     assert.ok(parts[3].indexOf('test-postmortem-details.js') != -1);
  154   });
  155   verifiers.push(function verifyJsfunctionS(testlines) {
  156     var foundtest = false, founditer = false;
  157     assert.ok(testlines.length > 1);
  158     testlines.forEach(function (line) {
  159       var parts = line.split(/\s+/);
  160       if (parts[2] == 'myIterFunction') {
  161         assert.equal(parts[1], '3');
  162         founditer = true;
  163       } else if (parts[2] == 'myTestFunction') {
  164         foundtest = true;
  165         assert.equal(parts[1], '1');
  166       }
  167     });
  168     assert.ok(foundtest);
  169     assert.ok(founditer);
  170   });
  171   verifiers.push(function verifyJssource(testlines) {
  172     var content = testlines.join('\n');
  173     assert.ok(testlines[0].indexOf('test-postmortem-details.js') != -1);
  174     assert.ok(content.indexOf('function myTestFunction()\n') != -1);
  175     assert.ok(content.indexOf('return (new Buffer(bufstr));\n') != -1);
  176   });
  177 
  178   var mod = util.format('::load %s\n',
  179                         path.join(__dirname,
  180                                   '..',
  181                                   '..',
  182                                   'out',
  183                                   'Release',
  184                                   'mdb_v8.so'));
  185   mdb.stdin.write(mod);
  186   mdb.stdin.write('!echo test: jsconstructor\n');
  187   mdb.stdin.write('::findjsobjects -p my_buffer | ::findjsobjects | ' +
  188       '::jsprint -b length ! awk -F: \'$2 == ' + bufstr.length + '{ print $1 }\'' +
  189       '| head -1 > ' + tmpfile + '\n');
  190   mdb.stdin.write('::cat ' + tmpfile + ' | ::jsconstructor\n');
  191   mdb.stdin.write('!echo test: nodebuffer\n');
  192   mdb.stdin.write('::cat ' + tmpfile + ' | ::nodebuffer\n');

>

Manual tests

::jsstack -v seems to get the source of functions wrong

For instance, for this stack trace:

native: libc.so.1`mutex_lock_impl+0x127
native: libc.so.1`mutex_lock+0x13
native: v8::internal::Debugger::IsDebuggerActive+0x28
native: v8::internal::FullCodeGenerator::SetStatementPosition+0x28
native: v8::internal::FullCodeGenerator::VisitIfStatement+0x1f
native: v8::internal::AstVisitor::VisitStatements+0x43
native: v8::internal::FullCodeGenerator::VisitBlock+0xde
native: v8::internal::FullCodeGenerator::VisitIfStatement+0x2a9
native: v8::internal::AstVisitor::VisitStatements+0x43
native: v8::internal::FullCodeGenerator::Generate+0x91d
native: v8::internal::FullCodeGenerator::MakeCode+0x279
native: _ZN2v88internalL24GetUnoptimizedCodeCommonEPNS0_15CompilationInf...
native: v8::internal::Compiler::GetUnoptimizedCode+0xd1
native: v8::internal::RuntimeHidden_CompileUnoptimized+0xc2
        (1 internal frame elided)
        (1 internal frame elided)
js:     <anonymous> (as Readable.read)
js:     <anonymous> (as Socket.read)
js:     Socket
        (1 internal frame elided)
js:     createSocket
js:     <anonymous> (as <anon>)
        (1 internal frame elided)
js:     forEach
        (1 internal frame elided)
js:     <anonymous> (as ChildProcess.spawn)
js:     <anonymous> (as exports.spawn)
        (1 internal frame elided)
js:     <anonymous> (as <anon>)
        (1 internal frame elided)
js:     <anonymous> (as Module._compile)
js:     <anonymous> (as Module._extensions..js)
js:     <anonymous> (as Module.load)
js:     <anonymous> (as Module._load)
js:     <anonymous> (as Module.runMain)
js:     startup
js:     <anonymous> (as <anon>)
        (1 internal frame elided)
        (1 internal frame elided)
native: _ZN2v88internalL6InvokeEbNS0_6HandleINS0_10JSFunctionEEENS1_INS0...
native: v8::internal::Execution::Call+0xca
native: v8::Function::Call+0xcd
native: node::Load+0x1ea
native: node::CreateEnvironment+0x3cd
native: node::Start+0x112
native: _start+0x6c

::jsstack -v seems to highlight too much code. For the following frame:

js:     <anonymous> (as Socket.read)

It highlights:

176   this._writableState.decodeStrings = false;
            177 
            178   // default to *not* allowing half open sockets
            179   this.allowHalfOpen = options && options.allowHalfOpen || false;
            180 
            181   // if we have a handle, then start the flow of data into the
            182   // buffer.  if not, then this will happen when we connect
            183   if (this._handle && options.readable !== false)
            184     this.read(0);
            185 }
            186 util.inherits(Socket, stream.Duplex);
            187 
            188 // the user has called .end(), and all the bytes have been
            189 // sent out to the other side.
            190 // If allowHalfOpen is false, or if the readable side has
            191 // ended already, then destroy.
            192 // If allowHalfOpen is true, then we need to do a shutdown,
            193 // so that only the writable side will be cleaned up.
            194 function onSocketFinish() {
            195   // If still connecting - defer handling 'finish' until 'connect' will happen
            196   if (this._connecting) {
            197     debug('osF: not yet connected');
            198     return this.once('connect', onSocketFinish);
            199   }
            200 
            201   debug('onSocketFinish');
            202   if (!this.readable || this._readableState.ended) {
            203     debug('oSF: ended, destroy', this._readableState);
            204     return this.destroy();
            205   }
            206 
            207   debug('oSF: not ended, call shutdown()');
            208 
            209   // otherwise, just shutdown, or destroy() if not possible
            210   if (!this._handle || !this._handle.shutdown)
            211     return this.destroy();
            212 
            213   var req = { oncomplete: afterShutdown };
            214   var err = this._handle.shutdown(req);

and much more (output truncated because it's really long).

Minor annoyances

Different types of frames displayed as the same type

8047a8c 0xbb30fe19 <InternalFrame>
8047ac8 0xbb30a0aa <EntryFrame>

turns into:

(1 internal frame elided)
(1 internal frame elided)

It seems that we're loosing a bit of info here.

Not having the filename displayed by default for a JS frame

That's very subjective though.

When using ::jsstack -vn0, the internal frames look like they're part of the next frame

It seems a bit confusing to me. Example:

native: libc.so.1`mutex_lock_impl+0x127
native: libc.so.1`mutex_lock+0x13
native: v8::internal::Debugger::IsDebuggerActive+0x28
native: v8::internal::FullCodeGenerator::SetStatementPosition+0x28
native: v8::internal::FullCodeGenerator::VisitIfStatement+0x1f
native: v8::internal::AstVisitor::VisitStatements+0x43
native: v8::internal::FullCodeGenerator::VisitBlock+0xde
native: v8::internal::FullCodeGenerator::VisitIfStatement+0x2a9
native: v8::internal::AstVisitor::VisitStatements+0x43
native: v8::internal::FullCodeGenerator::Generate+0x91d
native: v8::internal::FullCodeGenerator::MakeCode+0x279
native: _ZN2v88internalL24GetUnoptimizedCodeCommonEPNS0_15CompilationInf...
native: v8::internal::Compiler::GetUnoptimizedCode+0xd1
native: v8::internal::RuntimeHidden_CompileUnoptimized+0xc2
        (1 internal frame elided)
        (1 internal frame elided)
js:     <anonymous> (as Readable.read)
          file: _stream_readable.js
          posn: position 5121
          this: 2630ab0f84f9 (JSObject: Socket)
          arg1: 0 (SMI: value = 0)
js:     <anonymous> (as Socket.read)
          file: net.js
          posn: position 5121
          this: 2630ab0f84f9 (JSObject: Socket)
          arg1: 0 (SMI: value = 0)
js:     Socket
          file: net.js
          posn: position 134221829
          this: 2630ab0f84f9 (JSObject: Socket)
          arg1: 2630ab0f84c9 (JSObject: Object)
        (1 internal frame elided)
js:     createSocket
          file: child_process.js
          posn: position 4097
          this: 32337499a8a1 (<unknown>)
          arg1: 2630ab0f77a9 (JSObject: Pipe)
          arg2: 323374904181 (Oddball: "false")
js:     <anonymous> (as <anon>)
          file: child_process.js
          posn: position 5121
          this: 32337499a8a1 (<unknown>)
          arg1: 2630ab0f7769 (JSObject: Object)
          arg2: 0 (SMI: value = 0)
        (1 internal frame elided)
js:     forEach
          file: native array.js
          posn: line 265
          this: 2630ab0f7409 (JSArray)
          arg1: 2630ab0f83d9 (JSFunction)
          arg2: 32337499a8a1 (<unknown>)
        (1 internal frame elided)
js:     <anonymous> (as ChildProcess.spawn)
          file: child_process.js
          posn: position 5121
          this: 2630ab0f32f1 (JSObject: ChildProcess)
          arg1: 2630ab0f70f9 (JSObject: Object)
js:     <anonymous> (as exports.spawn)
          file: child_process.js
          posn: position 5153
          this: 32337499a8a1 (<unknown>)
        (1 internal frame elided)
js:     <anonymous> (as <anon>)
          file: /root/node/test/pummel/test-postmortem-details.js
          posn: position 5123
          this: 2630ab086f79 (JSObject: Object)
          arg1: 2630ab086f79 (JSObject: Object)
          arg2: 2630ab08c509 (JSFunction)
          arg3: 2630ab086e01 (JSObject: Module)
          arg4: 2630ab081f59 (ConsString)
          arg5: 2630ab08cde9 (ConsString)
        (1 internal frame elided)
js:     <anonymous> (as Module._compile)
          file: module.js             
          posn: position 5121         
          this: 2630ab086e01 (JSObject: Module)
          arg1: 2630ab08a701 (SeqOneByteString)
          arg2: 2630ab081f59 (ConsString)
js:     <anonymous> (as Module._extensions..js)
          file: module.js             
          posn: position 5121         
          this: 2630ab07c459 (JSObject: Object)
          arg1: 2630ab086e01 (JSObject: Module)
          arg2: 2630ab081f59 (ConsString)
js:     <anonymous> (as Module.load)  
          file: module.js             
          posn: position 5121         
          this: 2630ab086e01 (JSObject: Module)
          arg1: 2630ab081f59 (ConsString)
js:     <anonymous> (as Module._load) 
          file: module.js             
          posn: position 29697        
          this: 2630ab038b09 (JSFunction)
          arg1: 7c32e826f09 (ConsString)
          arg2: 323374904101 (Oddball: "null")
          arg3: 323374904161 (Oddball: "true")
js:     <anonymous> (as Module.runMain)
          file: module.js             
          posn: position 5121         
          this: 2630ab038b09 (JSFunction)
js:     startup                       
          file: node.js               
          posn: position 4097         
          this: 32337499a8a1 (<unknown>)
js:     <anonymous> (as <anon>)       
          file: node.js               
          posn: position 5123         
          this: 32337499a8a1 (<unknown>)
          arg1: 2630ab008161 (JSObject: process)
        (1 internal frame elided)     
        (1 internal frame elided)     
native: _ZN2v88internalL6InvokeEbNS0_6HandleINS0_10JSFunctionEEENS1_INS0...
native: v8::internal::Execution::Call+0xca
native: v8::Function::Call+0xcd       
native: node::Load+0x1ea              
native: node::CreateEnvironment+0x3cd 
native: node::Start+0x112             
native: _start+0x6c   

If we take this frame:

js:     forEach
          file: native array.js
          posn: line 265
          this: 2630ab0f7409 (JSArray)
          arg1: 2630ab0f83d9 (JSFunction)
          arg2: 32337499a8a1 (<unknown>)
        (1 internal frame elided)

It looks like (1 internal frame elided) is part of the forEach frame.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment