Merge pull request #350 from ONSdigital/add-tracing

Add opentracing instrumentation to GraphQL API

eq-author-api/README.md

@@ -84,3 +84,23 @@ It is possible to retrieve the full questionnaire data by making a `GET` request
 
 When the environment variable `ENABLE_IMPORT` is set to `true` then it exposes `/import` which will take the
 `POST` body and save it to the database. It performs no validation as it does this.
+
+## Instrumentation and tracing
+
+Instrumenting the GraphQL API is useful for troubleshooting errors and to help identify the root cause of slow running queries and mutations.
+
+The Author GraphQL API can be instrumented using [opentracing](https://opentracing.io) via the [apollo-opentracing](https://www.npmjs.com/package/apollo-opentracing) package.
+
+To enable instrumentation and to allow request tracing set the environment variable `ENABLE_OPENTRACING=true`. For convenience the [docker-compose-with-tracing.yml](docker-compose.yml) configuration that has been pre-configured to instrument the API, produce tracing metrics using Prometheus and collect the tracing output using [Jaeger](https://www.npmjs.com/package/jaeger-client).
+
+This configuration is only intended for local development and should not be used for production.
+
+To run the author API with instrumentation and request tracing enabled, simply run:
+
+```
+docker-compose up
+```
+
+Once running, the trace metrics and spans can be viewed by browsing to the Jaeger UI which is exposed on port `16686`.
+
+[http://localhost:16686](http://0.0.0.0:16686)

eq-author-api/app.js

@@ -2,9 +2,10 @@ require("dotenv").config();
 
 const logger = require("pino")();
 
-const server = require("./server");
+const { createApp } = require("./server");
 
 const { PORT = 4000 } = process.env;
+const server = createApp();
 
 server.listen(PORT, "0.0.0.0", () => {
   logger.child({ port: PORT }).info("Listening on port");

eq-author-api/docker-compose.yml

@@ -5,8 +5,10 @@ services:
       context: .
     depends_on:
       - dynamo
+      - jaeger
     links:
       - dynamo
+      - jaeger
     volumes:
       - .:/app
     ports:
@@ -23,10 +25,27 @@ services:
       - RUNNER_SESSION_URL=http://localhost:5000/session?token=
       - PUBLISHER_URL=http://localhost:9000/publish/
       - ENABLE_IMPORT=true
+      - JAEGER_SERVICE_NAME=eq_author_api
+      - JAEGER_ENDPOINT=http://jaeger:14268/api/traces
+      - JAEGER_SAMPLER_MANAGER_HOST_PORT=http://jaeger:5778/sampling
+      - JAEGER_SAMPLER_TYPE=probabilistic
+      - JAEGER_SAMPLER_PARAM=1
     entrypoint:
       - yarn
       - start:dev
   dynamo:
     image: amazon/dynamodb-local
     ports:
       - 8050:8000
+
+  jaeger:
+    image: jaegertracing/all-in-one:1.11
+    ports:
+      - 5775/udp
+      - 6831/udp
+      - 6832/udp
+      - 5778
+      - 14250
+      - 14268
+      - 16686:16686
+

eq-author-api/package.json

@@ -5,14 +5,15 @@
   "license": "MIT",
   "scripts": {
     "start": "node app.js",
-    "start:dev": "NODE_ENV=development nodemon --ignore 'data/ migrations/' --inspect=0.0.0.0:5858",
+    "start:dev": "ENABLE_OPENTRACING=true NODE_ENV=development nodemon --ignore 'data/ migrations/' --inspect=0.0.0.0:5858",
     "lint": "eslint .",
     "test": "./scripts/test.sh",
     "test:breakingChanges": "node scripts/checkForBreakingChanges.js",
     "dynamodb-admin": "AWS_ACCESS_KEY_ID=dummy AWS_SECRET_ACCESS_KEY=dummy DYNAMO_ENDPOINT=http://localhost:8050 dynamodb-admin",
     "create-migration": "node scripts/createMigration.js"
   },
   "dependencies": {
+    "apollo-opentracing": "^1.2.4",
     "apollo-server-express": "latest",
     "body-parser": "latest",
     "chalk": "latest",
@@ -30,6 +31,7 @@
     "graphql-tools": "latest",
     "graphql-type-json": "latest",
     "helmet": "latest",
+    "jaeger-client": "^3.15.0",
     "js-yaml": "latest",
     "json-stable-stringify": "latest",
     "json-web-key": "latest",
@@ -39,6 +41,7 @@
     "lodash": "latest",
     "node-jose": "latest",
     "pino-noir": "latest",
+    "prom-client": "^11.3.0",
     "uuid": "latest",
     "wait-on": "latest"
   },

eq-author-api/server.js

@@ -15,56 +15,77 @@ const exportQuestionnaire = require("./middleware/export");
 const importQuestionnaire = require("./middleware/import");
 const schema = require("./schema");
 
-const app = express();
-const pino = pinoMiddleware({
-  serializers: noir(["req.headers.authorization"], "[Redacted]"),
-});
-const logger = pino.logger;
+const createApp = () => {
+  const app = express();
+  const pino = pinoMiddleware({
+    serializers: noir(["req.headers.authorization"], "[Redacted]"),
+  });
+  const logger = pino.logger;
 
-app.use(
-  "/graphql",
-  helmet({
-    referrerPolicy: {
-      policy: "no-referrer",
-    },
-    frameguard: {
-      action: "deny",
-    },
-    contentSecurityPolicy: {
-      directives: {
-        defaultSrc: ["'self'"],
-        objectSrc: ["'none'"],
-        baseUri: ["'none'"],
-        fontSrc: ["'self'", "'https://fonts.gstatic.com'"],
-        scriptSrc: [
-          "'self'",
-          "'https://www.googleapis.com/identitytoolkit/v3'",
-        ],
+  let extensions = [];
+  if (process.env.ENABLE_OPENTRACING === "true") {
+    const OpentracingExtension = require("apollo-opentracing").default;
+    const { localTracer, serverTracer } = require("./tracer")(logger);
+    extensions = [
+      () =>
+        new OpentracingExtension({
+          server: serverTracer,
+          local: localTracer,
+        }),
+    ];
+  }
+
+  app.use(
+    "/graphql",
+    helmet({
+      referrerPolicy: {
+        policy: "no-referrer",
+      },
+      frameguard: {
+        action: "deny",
       },
+      contentSecurityPolicy: {
+        directives: {
+          defaultSrc: ["'self'"],
+          objectSrc: ["'none'"],
+          baseUri: ["'none'"],
+          fontSrc: ["'self'", "'https://fonts.gstatic.com'"],
+          scriptSrc: [
+            "'self'",
+            "'https://www.googleapis.com/identitytoolkit/v3'",
+          ],
+        },
+      },
+    }),
+    pino,
+    cors(),
+    createAuthMiddleware(logger),
+    loadQuestionnaire,
+    runQuestionnaireMigrations(logger)(require("./migrations"))
+  );
+
+  const server = new ApolloServer({
+    ...schema,
+    context: ({ req }) => {
+      return { questionnaire: req.questionnaire, auth: req.auth };
     },
-  }),
-  pino,
-  cors(),
-  createAuthMiddleware(logger),
-  loadQuestionnaire,
-  runQuestionnaireMigrations(logger)(require("./migrations"))
-);
+    extensions,
+  });
+
+  server.applyMiddleware({ app });
 
-const server = new ApolloServer({
-  ...schema,
-  context: ({ req }) => {
-    return { questionnaire: req.questionnaire, auth: req.auth };
-  },
-});
-server.applyMiddleware({ app });
+  app.get("/status", status);
 
-app.get("/status", status);
+  app.get("/launch/:questionnaireId", getLaunchUrl);
 
-app.get("/launch/:questionnaireId", getLaunchUrl);
+  app.get("/export/:questionnaireId", exportQuestionnaire);
+  if (process.env.ENABLE_IMPORT === "true") {
+    app.use(bodyParser.json()).post("/import", importQuestionnaire);
+  }
 
-app.get("/export/:questionnaireId", exportQuestionnaire);
-if (process.env.ENABLE_IMPORT === "true") {
-  app.use(bodyParser.json()).post("/import", importQuestionnaire);
-}
+  return app;
+};
 
-module.exports = app;
+module.exports = {
+  createApp,
+};

eq-author-api/server.test.js

@@ -4,14 +4,25 @@ const request = require("supertest");
 const { NUMBER } = require("./constants/answerTypes");
 const { buildQuestionnaire } = require("./tests/utils/questionnaireBuilder");
 
-const server = require("./server");
+const { createApp } = require("./server");
+const { introspectionQuery } = require("graphql");
+
+const jwt = require("jsonwebtoken");
+const uuid = require("uuid");
 
 describe("Server", () => {
   describe("export", () => {
+    let server;
+
+    beforeEach(() => {
+      server = createApp();
+    });
+
     it("should dump the questionnaire", async () => {
       const questionnaire = await buildQuestionnaire({
         sections: [{ pages: [{ answers: [{ type: NUMBER }] }] }],
       });
+
       const response = await request(server).get(`/export/${questionnaire.id}`);
 
       expect(response.headers["content-type"]).toMatch(/json/);
@@ -36,6 +47,9 @@ describe("Server", () => {
 
       const questionnaireJSON = JSON.parse(JSON.stringify(questionnaire));
 
+      process.env.ENABLE_IMPORT = "true";
+      const server = createApp();
+
       const response = await request(server)
         .post("/import")
         .send(questionnaireJSON);
@@ -56,4 +70,32 @@ describe("Server", () => {
       );
     });
   });
+
+  describe("tracing", () => {
+    it("should construct a server with opentracing enabled", async () => {
+      process.env.ENABLE_OPENTRACING = "true";
+      process.env.JAEGER_SERVICE_NAME = "test_service_name";
+      const server = createApp();
+      const token = jwt.sign(
+        {
+          sub: "tracing_test",
+          name: "tracing_test",
+          email: "tracing_test",
+          picture: "",
+        },
+        uuid.v4()
+      );
+      const response = await request(server)
+        .post("/graphql")
+        .set("authorization", `Bearer ${token}`)
+        .send({ query: introspectionQuery });
+
+      expect(response.statusCode).toBe(200);
+      expect(JSON.parse(response.text)).toEqual(
+        expect.objectContaining({
+          data: expect.any(Object),
+        })
+      );
+    });
+  });
 });

eq-author-api/tracer.js

@@ -0,0 +1,35 @@
+const {
+  initTracerFromEnv,
+  PrometheusMetricsFactory,
+} = require("jaeger-client");
+const promClient = require("prom-client");
+
+let tracer;
+
+const createTracer = logger => {
+  if (!tracer) {
+    const config = {
+      serviceName: process.env.JAEGER_SERVICE_NAME,
+    };
+
+    const namespace = config.serviceName;
+    const metrics = new PrometheusMetricsFactory(promClient, namespace);
+
+    const options = {
+      tags: {
+        "eq_author_api.version": process.env.EQ_AUTHOR_API_VERSION,
+      },
+      metrics,
+      logger,
+    };
+
+    tracer = initTracerFromEnv(config, options);
+  }
+
+  return tracer;
+};
+
+module.exports = logger => ({
+  localTracer: createTracer(logger),
+  serverTracer: createTracer(logger),
+});

eq-author-api/tracer.test.js

@@ -0,0 +1,55 @@
+const createTracer = require("./tracer");
+
+describe("createTracer", () => {
+  let logger;
+
+  const SERVICE_NAME = "service_name";
+  const API_VERSION = "api_version";
+
+  beforeEach(() => {
+    logger = {
+      info: jest.fn(),
+    };
+    process.env.JAEGER_SERVICE_NAME = SERVICE_NAME;
+    process.env.EQ_AUTHOR_API_VERSION = API_VERSION;
+  });
+
+  afterAll(() => {
+    delete process.env.JAEGER_SERVICE_NAME;
+    delete process.env.EQ_AUTHOR_API_VERSION;
+  });
+
+  it("should be a function", () => {
+    expect(createTracer).toEqual(expect.any(Function));
+  });
+
+  it("should return a local tracer", () => {
+    expect(createTracer(logger).localTracer).toEqual(expect.any(Object));
+  });
+
+  it("should return a server tracer", () => {
+    expect(createTracer(logger).serverTracer).toEqual(expect.any(Object));
+  });
+
+  it("should reuse the same tracer instance", () => {
+    expect(createTracer(logger).localTracer).toBe(
+      createTracer(logger).serverTracer
+    );
+  });
+
+  it("should set the tracer service name", () => {
+    expect(createTracer(logger).localTracer).toHaveProperty(
+      "_serviceName",
+      SERVICE_NAME
+    );
+  });
+
+  it("should tag the trace with API version number", () => {
+    expect(createTracer(logger).localTracer).toHaveProperty(
+      "_tags",
+      expect.objectContaining({
+        "eq_author_api.version": API_VERSION,
+      })
+    );
+  });
+});