Merge pull request #828 from artsy/trace-optimzations

Trace optimzations

index.js

@@ -23,6 +23,8 @@ import { forIn, has, assign } from "lodash"
 import uuid from "uuid/v1"
 import { fetchLoggerSetup, fetchLoggerRequestDone } from "lib/loaders/api/logger"
 import { timestamp } from "./lib/helpers"
+import { getNamedType, GraphQLObjectType } from "graphql"
+import * as introspectionQuery from "graphql/type/introspection"
 
 global.Promise = Bluebird
 
@@ -71,13 +73,31 @@ function drop_params(query) {
   return query.replace(/(\()([^\)]*)(\))/g, parse_args)
 }
 
-function trace(res, span) {
+function pushFinishedSpan(finishedSpans, span) {
+  const endTime = timestamp()
+  finishedSpans.push({ span, endTime })
+}
+
+function processFinishedSpans(finishedSpans) {
+  let i = 0
+  const iter = () => {
+    const entry = finishedSpans[i]
+    if (entry) {
+      const { span, endTime } = entry
+      span.finish(endTime)
+      i++
+      setImmediate(iter)
+    }
+  }
+  setImmediate(iter)
+}
+
+function trace(res, span, finishedSpans) {
   span.addTags({
     "http.status_code": res.statusCode,
   })
-  setImmediate(function () {
-    span.finish()
-  });
+  pushFinishedSpan(finishedSpans, span)
+  processFinishedSpans(finishedSpans)
 }
 
 app.use((req, res, next) => {
@@ -99,17 +119,22 @@ app.use((req, res, next) => {
 
   assign(req, { span })
 
-  res.on("finish", () => trace(res, span))
-  res.on("close", () => trace(res, span))
+  const finishedSpans = []
+  assign(req, { finishedSpans })
+
+  const finish = trace.bind(null, res, span, finishedSpans)
+  res.on("finish", finish)
+  res.on("close", finish)
 
   next()
 })
 
 function wrapResolve(typeName, fieldName, resolver) {
   return function (root, opts, req, { rootValue }) {
     const parentSpan = rootValue.span
-    const span = parentSpan.tracer().startSpan("metaphysics.resolver." + typeName + "." + fieldName,
-      { childOf: parentSpan.context() })
+    const span = parentSpan
+      .tracer()
+      .startSpan("metaphysics.resolver." + typeName + "." + fieldName, { childOf: parentSpan.context() })
     span.addTags({
       resource: typeName + ": " + fieldName,
       type: "web",
@@ -119,35 +144,32 @@ function wrapResolve(typeName, fieldName, resolver) {
     // Set the parent context to this span for any sub resolvers.
     rootValue.span = span // eslint-disable-line no-param-reassign
 
-    const result = resolver.apply(this, arguments);
+    const result = resolver.apply(this, arguments)
 
     // Return parent context to our parent for any resolvers called after this one.
     rootValue.span = parentSpan // eslint-disable-line no-param-reassign
 
     if (result instanceof Promise) {
       return result.finally(function () {
-        const endTime = timestamp()
-        setImmediate(() => span.finish(endTime))
+        pushFinishedSpan(rootValue.finishedSpans, span)
       })
     }
 
-    const endTime = timestamp()
-    setImmediate(() => span.finish(endTime))
-    return result;
-  };
+    pushFinishedSpan(rootValue.finishedSpans, span)
+    return result
+  }
 }
 
 // Walk the schema and for all object type fields with resolvers wrap them in our tracing resolver.
-forIn(schema._typeMap, function (value, key) {
-  const typeName = key
-  if (has(value, "_fields")) {
-    forIn(value._fields, function (field, fieldName) {
-      if (field.resolve instanceof Function) {
+forIn(schema._typeMap, function (type, typeName) {
+  if (!introspectionQuery[type] && has(type, "_fields")) {
+    forIn(type._fields, function (field, fieldName) {
+      if (field.resolve instanceof Function && getNamedType(field.type) instanceof GraphQLObjectType) {
         field.resolve = wrapResolve(typeName, fieldName, field.resolve) // eslint-disable-line no-param-reassign
       }
-    });
+    })
   }
-});
+})
 
 app.use(
   "/",
@@ -188,6 +210,7 @@ app.use(
         userID,
         defaultTimezone,
         span,
+        finishedSpans: request.finishedSpans,
         ...createLoaders(accessToken, userID, requestIDs),
       },
       formatError: graphqlErrorHandler(request.body),