From 61846c50623a9d40409752d429092b60f8e05f5b Mon Sep 17 00:00:00 2001 From: Matt Loring Date: Tue, 10 May 2016 17:33:42 -0700 Subject: [PATCH] Add support for log points --- lib/debuglet.js | 73 +++++++++++++++++++++++++++++--- lib/v8debugapi.js | 10 ++++- test/e2e/test.js | 50 +++++++++++++++++++++- test/standalone/test-debuglet.js | 27 +++++++++--- 4 files changed, 148 insertions(+), 12 deletions(-) diff --git a/lib/debuglet.js b/lib/debuglet.js index 006c4a5e..065e27d5 100644 --- a/lib/debuglet.js +++ b/lib/debuglet.js @@ -32,8 +32,8 @@ var assert = require('assert'); var NODE_VERSION_MESSAGE = 'Node.js version not supported. Node.js 5.2.0 and ' + ' versions older than 0.12 are not supported.'; -var BREAKPOINT_ACTION_MESSAGE = 'The only currently supported breakpoint action' + - ' is CAPTURE.'; +var BREAKPOINT_ACTION_MESSAGE = 'The only currently supported breakpoint actions' + + ' are CAPTURE and LOG.'; module.exports = Debuglet; @@ -219,7 +219,7 @@ Debuglet.prototype.scheduleBreakpointFetch_ = function(seconds) { } var bps = (body.breakpoints || []).filter(function(bp) { var action = bp.action || 'CAPTURE'; - if (action !== 'CAPTURE') { + if (action !== 'CAPTURE' && action !== 'LOG') { that.logger_.warn('Found breakpoint with invalid action:', action); bp.status = new StatusMessage(StatusMessage.UNSPECIFIED, BREAKPOINT_ACTION_MESSAGE, true); @@ -333,7 +333,7 @@ Debuglet.prototype.addBreakpoint_ = function(breakpoint, cb) { that.logger_.info('\tsuccessfully added breakpoint ' + breakpoint.id); that.activeBreakpointMap_[breakpoint.id] = breakpoint; - that.v8debug_.wait(breakpoint, function(err) { + that.v8debug_.wait(breakpoint, function waitHandler(err) { if (err) { that.logger_.error(err); cb(err); @@ -341,7 +341,20 @@ Debuglet.prototype.addBreakpoint_ = function(breakpoint, cb) { } that.logger_.info('Breakpoint hit!: ' + breakpoint.id); - that.completeBreakpoint_(breakpoint); + if (breakpoint.action === 'LOG') { + var message = Debuglet.format(breakpoint.logMessageFormat, + breakpoint.evaluatedExpressions.map(function(v) { + return v.value; + })); + console.log(message); + if (!that.completedBreakpointMap_[breakpoint.id]) { + setTimeout(function() { + that.v8debug_.wait(breakpoint, waitHandler); + }, 500); + } + } else { + that.completeBreakpoint_(breakpoint); + } }); }); }; @@ -434,3 +447,53 @@ Debuglet.mapSubtract = function mapSubtract(A, B) { return removed; }; +/** + * Formats the message base with placeholders `$0`, `$1`, etc + * by substituting the provided expressions. If more expressions + * are given than placeholders extra expressions are dropped. + */ +Debuglet.format = function(base, exprs) { + var tokens = Debuglet._tokenize(base, exprs.length); + for (var i = 0; i < tokens.length; i++) { + if (!tokens[i].v) { + continue; + } + if (tokens[i].v === '$$') { + tokens[i] = '$'; + continue; + } + for (var j = 0; j < exprs.length; j++) { + if (tokens[i].v === '$' + j) { + tokens[i] = exprs[j]; + break; + } + } + } + return tokens.join(''); +}; + +Debuglet._tokenize = function(base, exprLength) { + var acc = Debuglet._delimit(base, '$$'); + for (var i = exprLength - 1; i >= 0; i--) { + var newAcc = []; + for (var j = 0; j < acc.length; j++) { + if (acc[j].v) { + newAcc.push(acc[j]); + } else { + newAcc.push.apply(newAcc, Debuglet._delimit(acc[j], '$' + i)); + } + } + acc = newAcc; + } + return acc; +}; + +Debuglet._delimit = function(source, delim) { + var pieces = source.split(delim); + var dest = []; + dest.push(pieces[0]); + for (var i = 1; i < pieces.length; i++) { + dest.push({ v: delim }, pieces[i]); + } + return dest; +}; diff --git a/lib/v8debugapi.js b/lib/v8debugapi.js index 8b02f886..e8061dba 100644 --- a/lib/v8debugapi.js +++ b/lib/v8debugapi.js @@ -23,6 +23,7 @@ /** @const */ var state = require('./state.js'); /** @const */ var logModule = require('@google/cloud-diagnostics-common').logger; /** @const */ var apiclasses = require('./apiclasses.js'); +/** @const */ var _ = require('lodash'); /** @const */ var StatusMessage = apiclasses.StatusMessage; /** @const */ var messages = { @@ -484,7 +485,14 @@ module.exports.create = function(logger_, config_, fileStats_) { } } } - var captured = state.capture(execState, breakpoint.expressions, config); + var localConfig; + if (breakpoint.action === 'LOG') { + localConfig = { capture: { maxFrames: 0 } }; + _.defaultsDeep(localConfig, config); + } else { + localConfig = config; + } + var captured = state.capture(execState, breakpoint.expressions, localConfig); breakpoint.stackFrames = captured.stackFrames; breakpoint.variableTable = captured.variableTable; breakpoint.evaluatedExpressions = diff --git a/test/e2e/test.js b/test/e2e/test.js index 0265ebeb..5da8343f 100644 --- a/test/e2e/test.js +++ b/test/e2e/test.js @@ -36,6 +36,7 @@ var SCOPES = [ ]; var agent; +var transcript = ''; function apiRequest(authClient, url, method, body) { method = method || 'GET'; @@ -131,6 +132,45 @@ function runTest() { console.log('-- delete results', deleteResults); return debuggee; }) + .then(function(debuggee) { + // Set a breakpoint + console.log('-- setting a logpoint'); + var promise = setBreakpoint(debuggee, { + id: 'breakpoint-1', + location: {path: 'test.js', line: 5}, + condition: 'n === 10', + action: 'LOG', + expressions: ['n'], + log_message_format: 'n is: $0' + }); + // I don't know what I am doing. There is a better way to write the + // following using promises. + var result = promise.then(function(body) { + console.log('-- resolution of setBreakpoint', body); + assert.ok(body.breakpoint, 'should have set a breakpoint'); + var breakpoint = body.breakpoint; + assert.ok(breakpoint.id, 'breakpoint should have an id'); + assert.ok(breakpoint.location, 'breakpoint should have a location'); + assert.strictEqual(breakpoint.location.path, 'test.js'); + return { debuggee: debuggee, breakpoint: breakpoint }; + }); + return result; + }) + .then(function(result) { + assert.ok(result.breakpoint); + assert.ok(result.debuggee); + console.log('-- waiting a bit before running fib'); + return Q.delay(10 * 1000).then(function() { return result; }); + }) + .then(function(result) { + console.log('-- waiting before checking if the log was written'); + return Q.delay(10 * 1000).then(function() { return result; }); + }) + .then(function(result) { + assert(transcript.indexOf('n is: 10') !== -1); + deleteBreakpoint(result.debuggee, result.breakpoint).then(); + return result.debuggee; + }) .then(function(debuggee) { // Set a breakpoint console.log('-- setting a breakpoint'); @@ -183,6 +223,8 @@ function runTest() { }); assert.ok(arg, 'should find the n argument'); assert.strictEqual(arg.value, '10'); + console.log('-- checking log point was hit again'); + assert.ok(transcript.split('n is: 10').length > 4); console.log('Test passed'); process.exit(0); }) @@ -198,6 +240,7 @@ function runTest() { } if (cluster.isMaster) { + cluster.setupMaster({ silent: true }); var handler = function(m) { assert.ok(m.private_, 'debuglet has initialized'); var debuglet = m.private_; @@ -212,8 +255,13 @@ if (cluster.isMaster) { agent = m; } }; + var stdoutHandler = function(chunk) { + transcript += chunk; + }; for (var i = 0; i < 3; i++) { - cluster.fork().on('message', handler); + var worker = cluster.fork(); + worker.on('message', handler); + worker.process.stdout.on('data', stdoutHandler); } runTest(); } else { diff --git a/test/standalone/test-debuglet.js b/test/standalone/test-debuglet.js index 9b8d35fd..21243479 100644 --- a/test/standalone/test-debuglet.js +++ b/test/standalone/test-debuglet.js @@ -35,9 +35,9 @@ var bp = { action: 'CAPTURE', location: { path: 'fixtures/foo.js', line: 2 } }; -var logBp = { +var errorBp = { id: 'testLog', - action: 'LOG', + action: 'FOO', location: { path: 'fixtures/foo.js', line: 2 } }; @@ -166,12 +166,12 @@ describe(__filename, function(){ }) .get(BPS_PATH + '?success_on_timeout=true') .reply(200, { - breakpoints: [bp, logBp] + breakpoints: [bp, errorBp] }) - .put(BPS_PATH + '/' + logBp.id, function(body) { + .put(BPS_PATH + '/' + errorBp.id, function(body) { var status = body.breakpoint.status; return status.isError && - status.description.format.indexOf('action is CAPTURE') !== -1; + status.description.format.indexOf('actions are CAPTURE') !== -1; }) .reply(200); @@ -280,5 +280,22 @@ describe(__filename, function(){ assert.deepEqual(Debuglet.mapSubtract({}, b), []); }); }); + + describe('format', function() { + it('should be correct', function() { + assert.deepEqual(Debuglet.format('hi', [5]), 'hi'); + assert.deepEqual(Debuglet.format('hi $0', [5]), 'hi 5'); + assert.deepEqual(Debuglet.format('hi $0 $1', [5, 'there']), 'hi 5 there'); + assert.deepEqual(Debuglet.format('hi $0 $1', [5]), 'hi 5 $1'); + assert.deepEqual(Debuglet.format('hi $0 $1 $0', [5]), 'hi 5 $1 5'); + assert.deepEqual(Debuglet.format('hi $$', [5]), 'hi $'); + assert.deepEqual(Debuglet.format('hi $$0', [5]), 'hi $0'); + assert.deepEqual(Debuglet.format('hi $00', [5]), 'hi 50'); + assert.deepEqual(Debuglet.format('hi $0', ['$1', 5]), 'hi $1'); + assert.deepEqual(Debuglet.format('hi $11', + [0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 'a', 'b', 'c', 'd'] + ), 'hi b'); + }); + }); });