Merge branch 'public-master' into issue-2553

Author: Luke Sneeringer

README.md

@@ -1,6 +1,6 @@
 {
   "name": "@google-cloud/common",
-  "version": "0.13.4",
+  "version": "0.13.5",
   "author": "Google Inc.",
   "description": "Common components for Cloud APIs Node.js Client Libraries",
   "contributors": [

packages/common/package.json

@@ -43,9 +43,11 @@ var PROJECT_ID_TOKEN = '{{projectId}}';
  * @param {object} config - Configuration object.
  * @param {string} config.baseUrl - The base URL to make API requests to.
  * @param {string[]} config.scopes - The scopes required for the request.
- * @param {object} options - [Configuration object](#/docs).
+ * @param {object=} options - [Configuration object](#/docs).
  */
 function Service(config, options) {
+  options = options || {};
+
   var reqCfg = extend({}, config, {
     credentials: options.credentials,
     keyFile: options.keyFilename,

packages/common/src/service.js

@@ -65,6 +65,12 @@ describe('Service', function() {
   });
 
   describe('instantiation', function() {
+    it('should not require options', function() {
+      assert.doesNotThrow(function() {
+        new Service(CONFIG);
+      });
+    });
+
     it('should create an authenticated request factory', function() {
       var authenticatedRequest = {};
 

packages/common/test/service.js

@@ -40,6 +40,13 @@ var BUNYAN_TO_STACKDRIVER = {
   10: 'DEBUG'
 };
 
+/**
+ * Key to use in the Bunyan payload to allow users to indicate a trace for the
+ * request, and to store as an intermediate value on the log entry before it
+ * gets written to the Stackdriver logging API.
+ */
+var LOGGING_TRACE_KEY = 'logging.googleapis.com/trace';
+
 /**
  * This module provides support for streaming your Bunyan logs to
  * [Stackdriver Logging](https://cloud.google.com/logging).
@@ -56,6 +63,15 @@ var BUNYAN_TO_STACKDRIVER = {
  *     automatically, but you may optionally specify a specific monitored
  *     resource. For more information, see the
  *     [official documentation]{@link https://cloud.google.com/logging/docs/api/reference/rest/v2/MonitoredResource}
+ * @param {object=} options.serviceContext - For logged errors, we provide this
+ *     as the service context. For more information see
+ *     [this guide]{@link https://cloud.google.com/error-reporting/docs/formatting-error-messages}
+ *     and the [official documentation]{@link https://cloud.google.com/error-reporting/reference/rest/v1beta1/ServiceContext}.
+ * @param {string} options.serviceContext.service - An identifier of the
+ *     service, such as the name of the executable, job, or Google App Engine
+ *     service name.
+ * @param {string=} options.serviceContext.version - Represents the version of
+ *     the service.
  *
  * @example
  * var bunyan = require('bunyan');
@@ -85,6 +101,7 @@ function LoggingBunyan(options) {
 
   this.logName_ = options.logName || 'bunyan_log';
   this.resource_ = options.resource;
+  this.serviceContext_ = options.serviceContext;
 
   this.log_ = logging(options).log(this.logName_, {
     removeCircular: true
@@ -133,8 +150,6 @@ LoggingBunyan.prototype.formatEntry_ = function(record) {
     );
   }
 
-  record = extend({}, record);
-
   // Stackdriver Log Viewer picks up the summary line from the 'message' field
   // of the payload. Unless the user has provided a 'message' property also,
   // move the 'msg' to 'message'.
@@ -144,11 +159,9 @@ LoggingBunyan.prototype.formatEntry_ = function(record) {
     // higher). In this case we leave the 'msg' property intact.
     // https://cloud.google.com/error-reporting/docs/formatting-error-messages
     //
-    // TODO(ofrobots): when resource.type is 'global' we need to additionally
-    // provide serviceContext.service as part of the entry for Error Reporting
-    // to automatically pick up the error.
     if (record.err && record.err.stack) {
       record.message = record.err.stack;
+      record.serviceContext = this.serviceContext_;
     } else if (record.msg) {
       // Simply rename `msg` to `message`.
       record.message = record.msg;
@@ -173,9 +186,58 @@ LoggingBunyan.prototype.formatEntry_ = function(record) {
     delete record.httpRequest;
   }
 
+  if (record[LOGGING_TRACE_KEY]) {
+    entryMetadata.trace = record[LOGGING_TRACE_KEY];
+    delete record[LOGGING_TRACE_KEY];
+  }
+
   return this.log_.entry(entryMetadata, record);
 };
 
+/**
+ * Gets the current fully qualified trace ID when available from the
+ * @google-cloud/trace-agent library in the LogEntry.trace field format of:
+ * "projects/[PROJECT-ID]/traces/[TRACE-ID]".
+ */
+function getCurrentTraceFromAgent() {
+  var agent = global._google_trace_agent;
+  if (!agent || !agent.getCurrentContextId || !agent.getWriterProjectId) {
+    return null;
+  }
+
+  var traceId = agent.getCurrentContextId();
+  if (!traceId) {
+    return null;
+  }
+
+  var traceProjectId = agent.getWriterProjectId();
+  if (!traceProjectId) {
+    return null;
+  }
+
+  return `projects/${traceProjectId}/traces/${traceId}`;
+}
+
+/**
+ * Intercept log entries as they are written so we can attempt to add the trace
+ * ID in the same continuation as the function that wrote the log, because the
+ * trace agent currently uses continuation local storage for the trace context.
+ *
+ * By the time the Writable stream buffer gets flushed and _write gets called
+ * we may well be in a different continuation.
+ */
+LoggingBunyan.prototype.write = function(record, encoding, callback) {
+  record = extend({}, record);
+  if (!record[LOGGING_TRACE_KEY]) {
+    var trace = getCurrentTraceFromAgent();
+    if (trace) {
+      record[LOGGING_TRACE_KEY] = trace;
+    }
+  }
+
+  Writable.prototype.write.call(this, record, encoding, callback);
+};
+
 /**
  * Relay a log entry to the logging agent. This is called by bunyan through
  * Writable#write.

packages/logging-bunyan/src/index.js

@@ -56,7 +56,10 @@ describe('logging-bunyan', function() {
 
   var OPTIONS = {
     logName: 'log-name',
-    resource: {}
+    resource: {},
+    serviceContext: {
+      service: 'fake-service'
+    }
   };
 
   var RECORD = {
@@ -98,6 +101,10 @@ describe('logging-bunyan', function() {
       assert.strictEqual(loggingBunyan.resource_, OPTIONS.resource);
     });
 
+    it('should localize the provided service context', function() {
+      assert.strictEqual(loggingBunyan.serviceContext_, OPTIONS.serviceContext);
+    });
+
     it('should localize Log instance using provided name', function() {
       assert.strictEqual(fakeLoggingOptions_, OPTIONS);
       assert.strictEqual(fakeLogName_, OPTIONS.logName);
@@ -174,7 +181,8 @@ describe('logging-bunyan', function() {
         err: {
           stack: 'the stack'
         },
-        message: 'the stack'
+        message: 'the stack',
+        serviceContext: OPTIONS.serviceContext
       }, RECORD);
 
       loggingBunyan.log_.entry = function(entryMetadata, record_) {
@@ -223,6 +231,135 @@ describe('logging-bunyan', function() {
 
       loggingBunyan.formatEntry_(recordWithRequest);
     });
+
+    it('should promote prefixed trace property to metadata', function(done) {
+      var recordWithRequest = extend({
+        'logging.googleapis.com/trace': 'trace1'
+      }, RECORD);
+
+      loggingBunyan.log_.entry = function(entryMetadata, record) {
+        assert.deepStrictEqual(entryMetadata, {
+          resource: loggingBunyan.resource_,
+          timestamp: RECORD.time,
+          severity: LoggingBunyan.BUNYAN_TO_STACKDRIVER[RECORD.level],
+          trace: 'trace1'
+        });
+        assert.deepStrictEqual(record, RECORD);
+        done();
+      };
+
+      loggingBunyan.formatEntry_(recordWithRequest);
+    });
+  });
+
+  describe('write', function() {
+    var oldWritableWrite;
+    var oldTraceAgent;
+
+    beforeEach(function() {
+      oldWritableWrite = FakeWritable.prototype.write;
+      oldTraceAgent = global._google_trace_agent;
+    });
+
+    afterEach(function() {
+      FakeWritable.prototype.write = oldWritableWrite;
+      global._google_trace_agent = oldTraceAgent;
+    });
+
+    it('should not set trace property if trace unavailable', function(done) {
+      global._google_trace_agent = undefined;
+      FakeWritable.prototype.write = function(record, encoding, callback) {
+        assert.deepStrictEqual(record, RECORD);
+        assert.strictEqual(encoding, 'encoding');
+        assert.strictEqual(callback, assert.ifError);
+        assert.strictEqual(this, loggingBunyan);
+        done();
+      };
+
+      loggingBunyan.write(RECORD, 'encoding', assert.ifError);
+    });
+
+    it('should set prefixed trace property if trace available', function(done) {
+      global._google_trace_agent = {
+        getCurrentContextId: function() { return 'trace1'; },
+        getWriterProjectId: function() { return 'project1'; }
+      };
+      const recordWithoutTrace = extend({}, RECORD);
+      const recordWithTrace = extend({
+        'logging.googleapis.com/trace': 'projects/project1/traces/trace1'
+      }, RECORD);
+
+      FakeWritable.prototype.write = function(record, encoding, callback) {
+        // Check that trace field added to record before calling Writable.write
+        assert.deepStrictEqual(record, recordWithTrace);
+
+        // Check that the original record passed in was not mutated
+        assert.deepStrictEqual(recordWithoutTrace, RECORD);
+
+        assert.strictEqual(encoding, 'encoding');
+        assert.strictEqual(callback, assert.ifError);
+        assert.strictEqual(this, loggingBunyan);
+        done();
+      };
+
+      loggingBunyan.write(recordWithoutTrace, 'encoding', assert.ifError);
+    });
+
+    it('should leave prefixed trace property as is if set', function(done) {
+      var oldTraceAgent = global._google_trace_agent;
+      global._google_trace_agent = {
+        getCurrentContextId: function() { return 'trace-from-agent'; },
+        getWriterProjectId: function() { return 'project1'; }
+      };
+      const recordWithTraceAlreadySet = extend({
+        'logging.googleapis.com/trace': 'trace-already-set'
+      }, RECORD);
+
+      FakeWritable.prototype.write = function(record, encoding, callback) {
+        assert.deepStrictEqual(record, recordWithTraceAlreadySet);
+        assert.strictEqual(encoding, '');
+        assert.strictEqual(callback, assert.ifError);
+        assert.strictEqual(this, loggingBunyan);
+        done();
+      };
+
+      loggingBunyan.write(recordWithTraceAlreadySet, '', assert.ifError);
+
+      global._google_trace_agent = oldTraceAgent;
+    });
+  });
+
+  it('should not set prefixed trace property if trace unavailable', function() {
+    FakeWritable.prototype.write = function(record, encoding, callback) {
+      assert.deepStrictEqual(record, RECORD);
+      assert.strictEqual(encoding, '');
+      assert.strictEqual(callback, assert.ifError);
+      assert.strictEqual(this, loggingBunyan);
+    };
+    var oldTraceAgent = global._google_trace_agent;
+
+    global._google_trace_agent = {};
+    loggingBunyan.write(RECORD, '', assert.ifError);
+
+    global._google_trace_agent = {
+      getCurrentContextId: function() { return null; },
+      getWriterProjectId: function() { return null; }
+    };
+    loggingBunyan.write(RECORD, '', assert.ifError);
+
+    global._google_trace_agent = {
+      getCurrentContextId: function() { return null; },
+      getWriterProjectId: function() { return 'project1'; }
+    };
+    loggingBunyan.write(RECORD, '', assert.ifError);
+
+    global._google_trace_agent = {
+      getCurrentContextId: function() { return 'trace1'; },
+      getWriterProjectId: function() { return null; }
+    };
+    loggingBunyan.write(RECORD, '', assert.ifError);
+
+    global._google_trace_agent = oldTraceAgent;
   });
 
   describe('_write', function() {
@@ -303,4 +440,4 @@ describe('logging-bunyan', function() {
       });
     });
   });
-});
+});