feat: support tracing for untranspiled async/await in Node 8+ (#775)

kjin · web-flow · commit 30d0529f4e0d · 2018-06-28T09:53:41.000-07:00
diff --git a/.circleci/config.yml b/.circleci/config.yml
@@ -4,8 +4,6 @@
 node_modules_cache_key: &node_modules_cache_key node-modules-cache-{{ .Environment.CIRCLE_JOB }}-{{ arch }}-{{ checksum "package.json" }}-{{ checksum "package-lock.json" }}
 test_fixtures_cache_key: &test_fixtures_cache_key test-fixtures-cache-{{ .Environment.CIRCLE_JOB }}-{{ arch }}-{{ checksum "test/fixtures/plugin-fixtures.json" }}
 plugin_types_cache_key: &plugin_types_cache_key plugin-types-cache-{{ .Environment.CIRCLE_JOB }}-{{ arch }}-{{ checksum "src/plugins/types/index.d.ts" }}
-test_env: &test_env
-  GCLOUD_TRACE_NEW_CONTEXT: 1
 release_tags: &release_tags
   tags:
     only: /^v\d+(\.\d+){2}(-.*)?$/
@@ -126,7 +124,6 @@ jobs:
   node4:
     docker:
       - image: node:4
-        environment: *test_env
       - *mongo_service
       - *redis_service
       - *postgres_service
@@ -135,7 +132,6 @@ jobs:
   node6:
     docker:
       - image: node:6
-        environment: *test_env
       - *mongo_service
       - *redis_service
       - *postgres_service
@@ -144,7 +140,6 @@ jobs:
   node8:
     docker:
       - image: node:8
-        environment: *test_env
       - *mongo_service
       - *redis_service
       - *postgres_service
@@ -153,7 +148,6 @@ jobs:
   node9:
     docker:
       - image: node:9
-        environment: *test_env
       - *mongo_service
       - *redis_service
       - *postgres_service
@@ -162,7 +156,6 @@ jobs:
   node10:
     docker:
       - image: node:10
-        environment: *test_env
       - *mongo_service
       - *redis_service
       - *postgres_service
diff --git a/CONTRIBUTING.md b/CONTRIBUTING.md
@@ -12,7 +12,6 @@ The command `npm test` tests code the same way that our CI will test it. This is
 
 There are a couple of environmental variables to note:
 
-- Setting `GCLOUD_TRACE_NEW_CONTEXT` (to any string) activates `async_hooks`-based tracing on Node 8+. On versions of Node where `async_hooks` is available, tests should pass whether this variable is set or not.
 - Setting `TRACE_TEST_EXCLUDE_INTEGRATION` (to any string) disables plugin tests when the command `npm run unit-test` is run. This is recommended for changes that do not affect plugins.
   - Some integration tests depend on locally running database services. On Unix, you can use `./bin/docker-trace.sh start` to start these services.
 
diff --git a/README.md b/README.md
@@ -120,23 +120,14 @@ A fully detailed overview of the `TraceApi` object is available [here](doc/trace
 
 ## How does automatic tracing work?
 
-The Trace Agent automatically patches well-known modules to insert calls to functions that start, label, and end spans to measure latency of RPCs (such as mysql, redis, etc.) and incoming requests (such as express, hapi, etc.). As each RPC is typically performed on behalf of an incoming request, we must make sure that this association is accurately reflected in span data. To provide a uniform, generalized way of keeping track of which RPC belongs to which incoming request, we rely on the [`continuation-local-storage`][continuation-local-storage] module to keep track of the "trace context" across asynchronous boundaries.
+The Trace Agent automatically patches well-known modules to insert calls to functions that start, label, and end spans to measure latency of RPCs (such as mysql, redis, etc.) and incoming requests (such as express, hapi, etc.). As each RPC is typically performed on behalf of an incoming request, we must make sure that this association is accurately reflected in span data. To provide a uniform, generalized way of keeping track of which RPC belongs to which incoming request, we rely on the following mechanisms to keep track of the "trace context" across asynchronous boundaries:
+  * [`continuation-local-storage`][continuation-local-storage] (which relies on [`async-listener`][async-listener]) in Node 6
+  * [`async_hooks`][async-hooks] in Node 8+
 
-`continuation-local-storage`, which relies on [`async-listener`][async-listener] to preserve continuations over asynchronous boundaries, works great in most cases. However, it does have some limitations that can prevent us from being able to properly propagate trace context:
+These mechanisms work great in most cases. However, they do have some limitations that can prevent us from being able to properly propagate trace context:
 
 * It is possible that a module does its own queuing of callback functions – effectively merging asynchronous execution contexts. For example, one may write an http request buffering library that queues requests and then performs them in a batch in one shot. In such a case, when all the callbacks fire, they will execute in the context which flushed the queue instead of the context which added the callbacks to the queue. This problem is called the pooling problem or the [user-space queuing problem][queuing-problem], and is a fundamental limitation of JavaScript. If your application uses such code, you will notice that RPCs from many requests are showing up under a single trace, or that certain portions of your outbound RPCs do not get traced. In such cases we try to work around the problem through monkey patching, or by working with the library authors to fix the code to properly propagate context. However, finding problematic code is not always trivial.
-* Presently, it is not possible for `async-listener` to keep track of transitions across `await`-ed lines in ES7 [`async` functions][async-await-docs] that are available with Node 7.6+. If your application uses untranspiled `async` functions, we will not be properly track RPCs.
-
-### Tracing with `async/await`
-
-Starting in module version 2.2, the Trace Agent ships with an experimental implementation (using the Node 8 `async_hooks` API) that supports `async`/`await`. To enable this implementation, run your application with the environmental variable `GCLOUD_TRACE_NEW_CONTEXT` set:
-
-```bash
-# Requires Node 8+
-$ GCLOUD_TRACE_NEW_CONTEXT=1 npm start
-```
-
-We are actively looking for feedback on this new implementation. Please file an issue if you encounter unexpected or unwanted behavior.
+* If your application uses untranspiled `async` functions, you must use Node 8+. (Untranspiled `async` functions are supported from Node 7.6 onward, but we do not support tracing these functions in Node 7.)
 
 ## Contributing changes
 
diff --git a/appveyor.yml b/appveyor.yml
@@ -16,7 +16,6 @@ install:
   # Get the latest stable version of Node.js or io.js
   - ps: Install-Product node $env:nodejs_version
   - SET GCLOUD_PROJECT=0
-  - SET GCLOUD_TRACE_NEW_CONTEXT=1
   - SET TRACE_TEST_EXCLUDE_INTEGRATION=1
 
 # Post-install test scripts.
diff --git a/src/config.ts b/src/config.ts
@@ -32,8 +32,7 @@ export interface Config {
    *   Node binary version requirements are not met.
    * - 'async-listener' uses an implementation of CLS on top of the
    *   `continuation-local-storage` module.
-   * - 'auto' behaves like 'async-hooks' on Node 8+ when the
-   *   GCLOUD_TRACE_NEW_CONTEXT env variable is set, and 'async-listener'
+   * - 'auto' behaves like 'async-hooks' on Node 8+, and 'async-listener'
    *   otherwise.
    * - 'none' disables CLS completely.
    * - 'singular' allows one root span to exist at a time. This option is meant
diff --git a/src/index.ts b/src/index.ts
@@ -79,8 +79,7 @@ function initConfig(projectConfig: Forceable<Config>):
 
   // If the CLS mechanism is set to auto-determined, decide now what it should
   // be.
-  const ahAvailable = semver.satisfies(process.version, '>=8') &&
-      process.env.GCLOUD_TRACE_NEW_CONTEXT;
+  const ahAvailable = semver.satisfies(process.version, '>=8');
   if (config.clsMechanism === 'auto') {
     config.clsMechanism = ahAvailable ? 'async-hooks' : 'async-listener';
   }
diff --git a/system-test/trace-express.js b/system-test/trace-express.js
@@ -42,8 +42,7 @@ const queryString = require('querystring');
 const uuid = require('uuid');
 const semver = require('semver');
 
-const usingAsyncHooks = semver.satisfies(process.version, '>=8') &&
-                        !!process.env.GCLOUD_TRACE_NEW_CONTEXT;
+const usingAsyncHooks = semver.satisfies(process.version, '>=8');
 console.log(`Running system test with usingAsyncHooks=${usingAsyncHooks}`);
 
 // TODO(ofrobots): this code should be moved to a better location. Perhaps
diff --git a/test/plugins/common.ts b/test/plugins/common.ts
@@ -35,7 +35,7 @@ var semver = require('semver');
 
 var logger = require('@google-cloud/common').logger;
 var trace = require('../../..');
-if (semver.satisfies(process.version, '>=8') && process.env.GCLOUD_TRACE_NEW_CONTEXT) {
+if (semver.satisfies(process.version, '>=8')) {
   // Monkeypatch Mocha's it() to create a fresh context with each test case.
   var oldIt = global.it;
   global.it = Object.assign(function it(title, fn) {
diff --git a/test/test-config-cls.ts b/test/test-config-cls.ts
@@ -24,8 +24,7 @@ import {TraceCLSConfig, TraceCLSMechanism} from '../src/cls';
 import * as testTraceModule from './trace';
 
 describe('Behavior set by config for context propagation mechanism', () => {
-  const useAH = semver.satisfies(process.version, '>=8') &&
-      !!process.env.GCLOUD_TRACE_NEW_CONTEXT;
+  const useAH = semver.satisfies(process.version, '>=8');
   const autoMechanism =
       useAH ? TraceCLSMechanism.ASYNC_HOOKS : TraceCLSMechanism.ASYNC_LISTENER;
   let capturedConfig: TraceCLSConfig|null;

Original file line number	Diff line number	Diff line change
`@@ -79,8 +79,7 @@ function initConfig(projectConfig: Forceable<Config>):`
`79`	`79`
`80`	`80`	`// If the CLS mechanism is set to auto-determined, decide now what it should`
`81`	`81`	`// be.`
`82`		`- const ahAvailable = semver.satisfies(process.version, '>=8') &&`
`83`		`- process.env.GCLOUD_TRACE_NEW_CONTEXT;`
	`82`	`+ const ahAvailable = semver.satisfies(process.version, '>=8');`
`84`	`83`	`if (config.clsMechanism === 'auto') {`
`85`	`84`	`config.clsMechanism = ahAvailable ? 'async-hooks' : 'async-listener';`
`86`	`85`	`}`