From 64f102e6d45bcb454d5a76067506dd63231808b7 Mon Sep 17 00:00:00 2001
From: Wyatt Johnson <wyattjoh@gmail.com>
Date: Wed, 18 Sep 2019 17:07:42 +0000
Subject: [PATCH] [CORL-540] Logging improvements (#2565)

* fix: enhanced errors around story creation

* feat: enhanced child loggers

* feat: logging enhancements
---
 scripts/compileRelay.ts                       |  2 +-
 src/core/common/errors.ts                     |  6 ++
 .../app/handlers/api/account/confirm.ts       | 13 +++--
 .../app/handlers/api/auth/local/forgot.ts     | 11 ++--
 src/core/server/app/handlers/api/graphql.ts   |  3 +-
 .../graphql/persistedQueryMiddleware.ts       | 27 ++++++---
 src/core/server/app/middleware/logging.ts     | 17 ++++--
 src/core/server/app/middleware/tenant.ts      |  9 ++-
 src/core/server/cron/accountDeletion.ts       |  4 +-
 src/core/server/cron/scheduled/job.ts         | 13 +++--
 src/core/server/errors/index.ts               | 19 ++++++-
 src/core/server/errors/translations.ts        |  1 +
 src/core/server/graph/common/context.ts       | 16 ++++--
 .../common/extensions/LoggerExtension.ts      | 16 +++++-
 .../server/graph/common/extensions/helpers.ts | 50 ++++++++++++++++-
 .../{tenant => common}/persisted/index.ts     |  0
 .../{tenant => common}/persisted/loader.ts    |  0
 .../{tenant => common}/persisted/mapper.ts    |  2 +-
 src/core/server/graph/tenant/context.ts       |  2 +-
 .../graph/tenant/subscriptions/server.ts      | 22 +++++---
 src/core/server/models/helpers/indexing.ts    |  9 ++-
 src/core/server/models/queries/queries.ts     |  3 +-
 src/core/server/models/story/index.ts         | 55 ++++++++++++-------
 src/core/server/models/user/user.ts           |  2 +-
 src/core/server/queue/Task.ts                 |  4 +-
 src/core/server/queue/tasks/mailer/index.ts   | 11 ++--
 .../server/queue/tasks/mailer/processor.ts    | 13 +++--
 .../server/queue/tasks/notifier/processor.ts  | 13 +++--
 src/core/server/queue/tasks/scraper.ts        | 17 +++---
 src/core/server/services/comments/index.ts    | 26 +++++----
 .../services/comments/moderation/index.ts     | 13 +++--
 .../services/comments/pipeline/phases/spam.ts |  9 ++-
 .../comments/pipeline/phases/toxic.ts         |  2 +-
 .../server/services/notifications/context.ts  |  2 +-
 src/core/server/services/queries/cache.ts     |  2 +-
 src/core/server/services/stories/index.ts     | 22 +++++---
 .../server/services/stories/scraper/index.ts  |  4 +-
 src/core/server/services/tenant/index.ts      |  4 +-
 src/core/server/types/express.ts              |  9 +++
 39 files changed, 318 insertions(+), 135 deletions(-)
 rename src/core/server/graph/{tenant => common}/persisted/index.ts (100%)
 rename src/core/server/graph/{tenant => common}/persisted/loader.ts (100%)
 rename src/core/server/graph/{tenant => common}/persisted/mapper.ts (97%)

diff --git a/scripts/compileRelay.ts b/scripts/compileRelay.ts
index 1c8c85b93..861cf6f56 100644
--- a/scripts/compileRelay.ts
+++ b/scripts/compileRelay.ts
@@ -74,7 +74,7 @@ if (persist) {
   if (fs.existsSync(persist)) {
     // Create the new filename.
     const name = path.basename(program.src);
-    const generated = "./src/core/server/graph/tenant/persisted/__generated__";
+    const generated = "./src/core/server/graph/common/persisted/__generated__";
 
     // Create the generated directory if it doesn't exist.
     fs.ensureDirSync(generated);
diff --git a/src/core/common/errors.ts b/src/core/common/errors.ts
index 009a61d67..0d557912c 100644
--- a/src/core/common/errors.ts
+++ b/src/core/common/errors.ts
@@ -44,6 +44,12 @@ export enum ERROR_CODES {
    */
   TOKEN_NOT_FOUND = "TOKEN_NOT_FOUND",
 
+  /**
+   * DUPLICATE_STORY_ID is used when trying to create a Story with the same ID
+   * as another Story.
+   */
+  DUPLICATE_STORY_ID = "DUPLICATE_STORY_ID",
+
   /**
    * DUPLICATE_STORY_URL is used when trying to create a Story with the same URL
    * as another Story.
diff --git a/src/core/server/app/handlers/api/account/confirm.ts b/src/core/server/app/handlers/api/account/confirm.ts
index 7d229f74a..876e4eccd 100644
--- a/src/core/server/app/handlers/api/account/confirm.ts
+++ b/src/core/server/app/handlers/api/account/confirm.ts
@@ -100,11 +100,14 @@ export const confirmRequestHandler = ({
 
       await userIDLimiter.test(req, targetUserID);
 
-      const log = coral.logger.child({
-        targetUserID,
-        requestingUserID: requestingUser.id,
-        tenantID: tenant.id,
-      });
+      const log = coral.logger.child(
+        {
+          targetUserID,
+          requestingUserID: requestingUser.id,
+          tenantID: tenant.id,
+        },
+        true
+      );
 
       // Lookup the user.
       const targetUser = await retrieveUser(mongo, tenant.id, targetUserID);
diff --git a/src/core/server/app/handlers/api/auth/local/forgot.ts b/src/core/server/app/handlers/api/auth/local/forgot.ts
index 0d14827d3..5c5e1bc5b 100644
--- a/src/core/server/app/handlers/api/auth/local/forgot.ts
+++ b/src/core/server/app/handlers/api/auth/local/forgot.ts
@@ -77,10 +77,13 @@ export const forgotHandler = ({
       // Limit based on the email address.
       await emailLimiter.test(req, email);
 
-      const log = coral.logger.child({
-        email,
-        tenantID: tenant.id,
-      });
+      const log = coral.logger.child(
+        {
+          email,
+          tenantID: tenant.id,
+        },
+        true
+      );
 
       // Lookup the user.
       const user = await retrieveUserWithProfile(mongo, tenant.id, {
diff --git a/src/core/server/app/handlers/api/graphql.ts b/src/core/server/app/handlers/api/graphql.ts
index 717a738c2..12d35c99f 100644
--- a/src/core/server/app/handlers/api/graphql.ts
+++ b/src/core/server/app/handlers/api/graphql.ts
@@ -36,7 +36,7 @@ export const graphQLHandler = ({
       }
 
       // Pull out some useful properties from Coral.
-      const { id, now, tenant, cache, logger } = req.coral;
+      const { id, now, tenant, cache, logger, persisted } = req.coral;
 
       if (!cache) {
         throw new Error("cache was not set");
@@ -52,6 +52,7 @@ export const graphQLHandler = ({
         id,
         now,
         req,
+        persisted,
         config,
         tenant,
         logger,
diff --git a/src/core/server/app/middleware/graphql/persistedQueryMiddleware.ts b/src/core/server/app/middleware/graphql/persistedQueryMiddleware.ts
index 85dac9860..62704fac5 100644
--- a/src/core/server/app/middleware/graphql/persistedQueryMiddleware.ts
+++ b/src/core/server/app/middleware/graphql/persistedQueryMiddleware.ts
@@ -1,17 +1,22 @@
 import { AppOptions } from "coral-server/app";
 import { RawQueryNotAuthorized } from "coral-server/errors";
-import { getPersistedQuery } from "coral-server/graph/tenant/persisted";
+import { getPersistedQuery } from "coral-server/graph/common/persisted";
 import { GQLUSER_ROLE } from "coral-server/graph/tenant/schema/__generated__/types";
 import { RequestHandler } from "coral-server/types/express";
 
 type PersistedQueryMiddlewareOptions = Pick<
   AppOptions,
-  "config" | "persistedQueryCache" | "persistedQueriesRequired"
+  "persistedQueryCache" | "persistedQueriesRequired"
 >;
 
-const persistedQueryMiddleware = (
-  options: PersistedQueryMiddlewareOptions
-): RequestHandler => async (req, res, next) => {
+const persistedQueryMiddleware = ({
+  persistedQueriesRequired,
+  persistedQueryCache,
+}: PersistedQueryMiddlewareOptions): RequestHandler => async (
+  req,
+  res,
+  next
+) => {
   try {
     if (!req.coral) {
       throw new Error("coral was not set");
@@ -25,12 +30,12 @@ const persistedQueryMiddleware = (
 
     // Handle the payload if it is a persisted query.
     const body = req.method === "GET" ? req.query : req.body;
-    const query = await getPersistedQuery(options.persistedQueryCache, body);
-    if (!query) {
+    const persisted = await getPersistedQuery(persistedQueryCache, body);
+    if (!persisted) {
       // Check to see if this is from an ADMIN token which is allowed to run
       // un-persisted queries.
       if (
-        options.persistedQueriesRequired &&
+        persistedQueriesRequired &&
         (!req.user || req.user.role !== GQLUSER_ROLE.ADMIN)
       ) {
         throw new RawQueryNotAuthorized(
@@ -41,7 +46,11 @@ const persistedQueryMiddleware = (
     } else {
       // The query was found for this operation, replace the query with the one
       // provided.
-      body.query = query.query;
+      body.query = persisted.query;
+
+      // Associate the persisted query with the request so it can be attached to
+      // the context.
+      req.coral.persisted = persisted;
     }
 
     return next();
diff --git a/src/core/server/app/middleware/logging.ts b/src/core/server/app/middleware/logging.ts
index 432902fbb..7658c2105 100644
--- a/src/core/server/app/middleware/logging.ts
+++ b/src/core/server/app/middleware/logging.ts
@@ -1,8 +1,11 @@
-import { ErrorRequestHandler, RequestHandler } from "express";
 import onFinished from "on-finished";
 import now from "performance-now";
 
 import logger from "coral-server/logger";
+import {
+  ErrorRequestHandler,
+  RequestHandler,
+} from "coral-server/types/express";
 
 export const accessLogger: RequestHandler = (req, res, next) => {
   const startTime = now();
@@ -14,10 +17,12 @@ export const accessLogger: RequestHandler = (req, res, next) => {
     // Get some extra goodies from the request.
     const userAgent = req.get("User-Agent");
 
+    // Grab the logger.
+    const log = req.coral ? req.coral.logger : logger;
+
     // Log this out.
-    logger.info(
+    log.debug(
       {
-        // traceID: req.id,
         url: req.originalUrl || req.url,
         method: req.method,
         statusCode: res.statusCode,
@@ -32,7 +37,11 @@ export const accessLogger: RequestHandler = (req, res, next) => {
 };
 
 export const errorLogger: ErrorRequestHandler = (err, req, res, next) => {
-  logger.error({ err }, "http error");
+  // Grab the logger.
+  const log = req.coral ? req.coral.logger : logger;
+
+  // Log this out.
+  log.error({ err }, "http error");
 
   next(err);
 };
diff --git a/src/core/server/app/middleware/tenant.ts b/src/core/server/app/middleware/tenant.ts
index f8c4eb6ba..2f7e02e15 100644
--- a/src/core/server/app/middleware/tenant.ts
+++ b/src/core/server/app/middleware/tenant.ts
@@ -26,7 +26,11 @@ export const tenantMiddleware = ({
       const now = new Date();
 
       // Set Coral on the request.
-      req.coral = { id, now, logger: logger.child({ traceID: id }) };
+      req.coral = {
+        id,
+        now,
+        logger: logger.child({ context: "http", contextID: id }, true),
+      };
     }
 
     // Set the Coral Tenant Cache on the request.
@@ -47,6 +51,9 @@ export const tenantMiddleware = ({
       return next(new TenantNotFoundError(req.hostname));
     }
 
+    // Augment the logger with the tenantID.
+    req.coral.logger = req.coral.logger.child({ tenantID: tenant.id }, true);
+
     // Attach the tenant to the request.
     req.coral.tenant = tenant;
 
diff --git a/src/core/server/cron/accountDeletion.ts b/src/core/server/cron/accountDeletion.ts
index e9a4970c1..69ac8500b 100644
--- a/src/core/server/cron/accountDeletion.ts
+++ b/src/core/server/cron/accountDeletion.ts
@@ -39,7 +39,7 @@ const deleteScheduledAccounts: ScheduledJobCommand<Options> = async ({
 }) => {
   // For each of the tenant's, process their users notifications.
   for await (const tenant of tenantCache) {
-    log = log.child({ tenantID: tenant.id });
+    log = log.child({ tenantID: tenant.id }, true);
 
     while (true) {
       const now = new Date();
@@ -77,6 +77,8 @@ const deleteScheduledAccounts: ScheduledJobCommand<Options> = async ({
             },
           },
         });
+      } else {
+        log.info({ userID: user.id }, "user did not have an email address");
       }
     }
   }
diff --git a/src/core/server/cron/scheduled/job.ts b/src/core/server/cron/scheduled/job.ts
index 83855d98a..bf11b65d9 100644
--- a/src/core/server/cron/scheduled/job.ts
+++ b/src/core/server/cron/scheduled/job.ts
@@ -21,10 +21,13 @@ export class ScheduledJob<T extends {} = {}> {
 
   constructor(context: T, opts: Options<T>) {
     this.context = context;
-    this.log = logger.child({
-      jobName: opts.name,
-      jobFrequency: opts.cronTime,
-    });
+    this.log = logger.child(
+      {
+        jobName: opts.name,
+        jobFrequency: opts.cronTime,
+      },
+      true
+    );
     this.job = new CronJob({
       cronTime: opts.cronTime,
       onTick: this.command(opts.command),
@@ -36,7 +39,7 @@ export class ScheduledJob<T extends {} = {}> {
 
   private command(command: ScheduledJobCommand<T>): CronCommand {
     return async () => {
-      const log = this.log.child({ scheduledExecutionID: uuid.v1() });
+      const log = this.log.child({ scheduledExecutionID: uuid.v1() }, true);
       log.debug("now starting scheduled job");
       const start = now();
       try {
diff --git a/src/core/server/errors/index.ts b/src/core/server/errors/index.ts
index 33ca90f7f..bc1791420 100644
--- a/src/core/server/errors/index.ts
+++ b/src/core/server/errors/index.ts
@@ -1,6 +1,7 @@
 // tslint:disable:max-classes-per-file
 
 import { FluentBundle } from "fluent/compat";
+import { MongoError } from "mongodb";
 import uuid from "uuid";
 import { VError } from "verror";
 
@@ -280,9 +281,23 @@ export class EmailNotSetError extends CoralError {
   }
 }
 
+export class DuplicateStoryIDError extends CoralError {
+  constructor(cause: MongoError, id: string, url?: string) {
+    super({
+      cause,
+      code: ERROR_CODES.DUPLICATE_STORY_ID,
+      context: { pvt: { id, url } },
+    });
+  }
+}
+
 export class DuplicateStoryURLError extends CoralError {
-  constructor(url: string) {
-    super({ code: ERROR_CODES.DUPLICATE_STORY_URL, context: { pvt: { url } } });
+  constructor(cause: MongoError, url: string, id?: string) {
+    super({
+      cause,
+      code: ERROR_CODES.DUPLICATE_STORY_URL,
+      context: { pvt: { id, url } },
+    });
   }
 }
 
diff --git a/src/core/server/errors/translations.ts b/src/core/server/errors/translations.ts
index d7d63a926..5bb374a4c 100644
--- a/src/core/server/errors/translations.ts
+++ b/src/core/server/errors/translations.ts
@@ -6,6 +6,7 @@ export const ERROR_TRANSLATIONS: Record<ERROR_CODES, string> = {
   COMMENT_NOT_FOUND: "error-commentNotFound",
   COMMENTING_DISABLED: "error-commentingDisabled",
   DUPLICATE_EMAIL: "error-duplicateEmail",
+  DUPLICATE_STORY_ID: "error-duplicateStoryID",
   DUPLICATE_STORY_URL: "error-duplicateStoryURL",
   DUPLICATE_USER: "error-duplicateUser",
   EMAIL_ALREADY_SET: "error-emailAlreadySet",
diff --git a/src/core/server/graph/common/context.ts b/src/core/server/graph/common/context.ts
index b408f7018..3838a854a 100644
--- a/src/core/server/graph/common/context.ts
+++ b/src/core/server/graph/common/context.ts
@@ -4,6 +4,7 @@ import uuid from "uuid";
 import { LanguageCode } from "coral-common/helpers/i18n/locales";
 import { Config } from "coral-server/config";
 import logger, { Logger } from "coral-server/logger";
+import { PersistedQuery } from "coral-server/models/queries";
 import { User } from "coral-server/models/user";
 import { I18n } from "coral-server/services/i18n";
 import { AugmentedRedis } from "coral-server/services/redis";
@@ -18,6 +19,7 @@ export interface CommonContextOptions {
   logger?: Logger;
   lang?: LanguageCode;
   disableCaching?: boolean;
+  persisted?: PersistedQuery;
   config: Config;
   i18n: I18n;
   pubsub: RedisPubSub;
@@ -28,6 +30,7 @@ export interface CommonContextOptions {
 export default class CommonContext {
   public readonly user?: User;
   public readonly req?: Request;
+  public readonly persisted?: PersistedQuery;
   public readonly id: string;
   public readonly config: Config;
   public readonly i18n: I18n;
@@ -45,6 +48,7 @@ export default class CommonContext {
     logger: log = logger,
     user,
     req,
+    persisted,
     config,
     i18n,
     lang = i18n.getDefaultLang(),
@@ -54,13 +58,17 @@ export default class CommonContext {
     disableCaching = false,
   }: CommonContextOptions) {
     this.id = id;
-    this.logger = log.child({
-      context: "graph",
-      contextID: id,
-    });
+    this.logger = log.child(
+      {
+        context: "graph",
+        contextID: id,
+      },
+      true
+    );
     this.now = now;
     this.user = user;
     this.req = req;
+    this.persisted = persisted;
     this.config = config;
     this.i18n = i18n;
     this.lang = lang;
diff --git a/src/core/server/graph/common/extensions/LoggerExtension.ts b/src/core/server/graph/common/extensions/LoggerExtension.ts
index 5889fad23..146f5b03f 100644
--- a/src/core/server/graph/common/extensions/LoggerExtension.ts
+++ b/src/core/server/graph/common/extensions/LoggerExtension.ts
@@ -7,7 +7,8 @@ import {
 import now from "performance-now";
 
 import CommonContext from "coral-server/graph/common/context";
-import { getOperationMetadata } from "./helpers";
+
+import { getOperationMetadata, getPersistedQueryMetadata } from "./helpers";
 
 export function logError(ctx: CommonContext, err: GraphQLError) {
   ctx.logger.error({ err }, "graphql query error");
@@ -16,12 +17,20 @@ export function logError(ctx: CommonContext, err: GraphQLError) {
 export function logQuery(
   ctx: CommonContext,
   document: DocumentNode,
+  persisted = ctx.persisted,
   responseTime?: number
 ) {
-  ctx.logger.debug(
+  ctx.logger.info(
     {
       responseTime,
-      ...getOperationMetadata(document),
+      authenticated: ctx.user ? true : false,
+      ...(persisted
+        ? // A persisted query was provided, we can pull the operation metadata
+          // out from the persisted object.
+          getPersistedQueryMetadata(persisted)
+        : // A persisted query was not provided, parse the operation metadata
+          // out from the document.
+          getOperationMetadata(document)),
     },
     "graphql query"
   );
@@ -44,6 +53,7 @@ export class LoggerExtension implements GraphQLExtension<CommonContext> {
         logQuery(
           o.executionArgs.contextValue,
           o.executionArgs.document,
+          undefined,
           responseTime
         );
       };
diff --git a/src/core/server/graph/common/extensions/helpers.ts b/src/core/server/graph/common/extensions/helpers.ts
index 3fa651a60..66a665ab2 100644
--- a/src/core/server/graph/common/extensions/helpers.ts
+++ b/src/core/server/graph/common/extensions/helpers.ts
@@ -1,6 +1,26 @@
-import { DocumentNode, OperationDefinitionNode } from "graphql";
+import {
+  DocumentNode,
+  OperationDefinitionNode,
+  OperationTypeNode,
+} from "graphql";
 
-export function getOperationMetadata(doc: DocumentNode) {
+import { PersistedQuery } from "coral-server/models/queries";
+
+export interface OperationMetadata {
+  operationName: string;
+  operation: OperationTypeNode;
+}
+
+/**
+ * getOperationMetadata will extract the operation metadata from the document
+ * node.
+ *
+ * @param doc the document node that can be used to extract operation metadata
+ *            from
+ */
+export const getOperationMetadata = (
+  doc: DocumentNode
+): Partial<OperationMetadata> => {
   if (doc.kind === "Document") {
     const operationDefinition = doc.definitions.find(
       ({ kind }) => kind === "OperationDefinition"
@@ -19,4 +39,30 @@ export function getOperationMetadata(doc: DocumentNode) {
   }
 
   return {};
+};
+
+interface PersistedQueryOperationMetadata extends OperationMetadata {
+  persistedQueryID: string;
+  persistedQueryBundle: string;
+  persistedQueryVersion: string;
 }
+
+/**
+ * getPersistedQueryMetadata will remap the persisted query to the operation
+ * metadata.
+ *
+ * @param persisted persisted query to remap to operation metadata
+ */
+export const getPersistedQueryMetadata = ({
+  id: persistedQueryID,
+  operation,
+  operationName,
+  bundle: persistedQueryBundle,
+  version: persistedQueryVersion,
+}: PersistedQuery): PersistedQueryOperationMetadata => ({
+  persistedQueryID,
+  persistedQueryBundle,
+  persistedQueryVersion,
+  operation,
+  operationName,
+});
diff --git a/src/core/server/graph/tenant/persisted/index.ts b/src/core/server/graph/common/persisted/index.ts
similarity index 100%
rename from src/core/server/graph/tenant/persisted/index.ts
rename to src/core/server/graph/common/persisted/index.ts
diff --git a/src/core/server/graph/tenant/persisted/loader.ts b/src/core/server/graph/common/persisted/loader.ts
similarity index 100%
rename from src/core/server/graph/tenant/persisted/loader.ts
rename to src/core/server/graph/common/persisted/loader.ts
diff --git a/src/core/server/graph/tenant/persisted/mapper.ts b/src/core/server/graph/common/persisted/mapper.ts
similarity index 97%
rename from src/core/server/graph/tenant/persisted/mapper.ts
rename to src/core/server/graph/common/persisted/mapper.ts
index 8310863f1..ce5e65b20 100644
--- a/src/core/server/graph/tenant/persisted/mapper.ts
+++ b/src/core/server/graph/common/persisted/mapper.ts
@@ -29,7 +29,7 @@ export async function getPersistedQuery(
     // empty.
     !(payload.query === "PERSISTED_QUERY" || payload.query === "")
   ) {
-    return null;
+    return undefined;
   }
 
   const query = await cache.get(payload.id);
diff --git a/src/core/server/graph/tenant/context.ts b/src/core/server/graph/tenant/context.ts
index b4ad0502e..f48e6be7e 100644
--- a/src/core/server/graph/tenant/context.ts
+++ b/src/core/server/graph/tenant/context.ts
@@ -49,7 +49,7 @@ export default class TenantContext extends CommonContext {
     super({
       ...options,
       lang: tenant.locale,
-      logger: logger.child({ tenantID: tenant.id }),
+      logger: logger.child({ tenantID: tenant.id }, true),
     });
 
     this.tenant = tenant;
diff --git a/src/core/server/graph/tenant/subscriptions/server.ts b/src/core/server/graph/tenant/subscriptions/server.ts
index 0419b6ea2..130b8ab9a 100644
--- a/src/core/server/graph/tenant/subscriptions/server.ts
+++ b/src/core/server/graph/tenant/subscriptions/server.ts
@@ -35,9 +35,10 @@ import {
   logQuery,
 } from "coral-server/graph/common/extensions";
 import { getOperationMetadata } from "coral-server/graph/common/extensions/helpers";
-import { getPersistedQuery } from "coral-server/graph/tenant/persisted";
+import { getPersistedQuery } from "coral-server/graph/common/persisted";
 import { GQLUSER_ROLE } from "coral-server/graph/tenant/schema/__generated__/types";
 import logger from "coral-server/logger";
+import { PersistedQuery } from "coral-server/models/queries";
 import { hasStaffRole } from "coral-server/models/user/helpers";
 import { extractTokenFromRequest } from "coral-server/services/jwt";
 
@@ -166,7 +167,10 @@ export function onConnect(options: OnConnectOptions): OnConnectFn {
 
 export type FormatResponseOptions = Pick<AppOptions, "metrics">;
 
-export function formatResponse({ metrics }: FormatResponseOptions) {
+export function formatResponse(
+  { metrics }: FormatResponseOptions,
+  persisted?: PersistedQuery
+) {
   return (
     value: ExecutionResult,
     { context, query }: ExecutionParams<TenantContext>
@@ -177,7 +181,7 @@ export function formatResponse({ metrics }: FormatResponseOptions) {
     }
 
     // Log out the query.
-    logQuery(context, query);
+    logQuery(context, query, persisted);
 
     // Increment the metrics if enabled.
     if (metrics) {
@@ -217,15 +221,12 @@ export function onOperation(options: OnOperationOptions) {
     message: OperationMessage,
     params: ExecutionParams<TenantContext>
   ) => {
-    // Attach the response formatter.
-    params.formatResponse = formatResponse(options);
-
     // Handle the payload if it is a persisted query.
-    const query = await getPersistedQuery(
+    const persisted = await getPersistedQuery(
       options.persistedQueryCache,
       message.payload
     );
-    if (!query) {
+    if (!persisted) {
       // Check to see if this is from an ADMIN token which is allowed to run
       // un-persisted queries.
       if (
@@ -241,9 +242,12 @@ export function onOperation(options: OnOperationOptions) {
     } else {
       // The query was found for this operation, replace the query with the one
       // provided.
-      params.query = query.query;
+      params.query = persisted.query;
     }
 
+    // Attach the response formatter.
+    params.formatResponse = formatResponse(options, persisted);
+
     return params;
   };
 }
diff --git a/src/core/server/models/helpers/indexing.ts b/src/core/server/models/helpers/indexing.ts
index 55b3dc5d3..77a4712f6 100644
--- a/src/core/server/models/helpers/indexing.ts
+++ b/src/core/server/models/helpers/indexing.ts
@@ -19,9 +19,12 @@ type IndexCreationFunction<T> = (
 export function createIndexFactory<T>(
   collection: Collection<T>
 ): IndexCreationFunction<T> {
-  const log = logger.child({
-    collectionName: collection.collectionName,
-  });
+  const log = logger.child(
+    {
+      collectionName: collection.collectionName,
+    },
+    true
+  );
 
   return async (
     indexSpec: IndexSpecification<T>,
diff --git a/src/core/server/models/queries/queries.ts b/src/core/server/models/queries/queries.ts
index 9274e3502..05dd01c68 100644
--- a/src/core/server/models/queries/queries.ts
+++ b/src/core/server/models/queries/queries.ts
@@ -1,3 +1,4 @@
+import { OperationTypeNode } from "graphql";
 import { Db } from "mongodb";
 
 import {
@@ -9,7 +10,7 @@ const collection = createCollection<Readonly<PersistedQuery>>("queries");
 
 export interface PersistedQuery {
   id: string;
-  operation: string;
+  operation: OperationTypeNode;
   operationName: string;
   query: string;
   bundle: string;
diff --git a/src/core/server/models/story/index.ts b/src/core/server/models/story/index.ts
index 02165e088..ce45cdd21 100644
--- a/src/core/server/models/story/index.ts
+++ b/src/core/server/models/story/index.ts
@@ -3,7 +3,10 @@ import uuid from "uuid";
 
 import { DeepPartial, Omit } from "coral-common/types";
 import { dotize } from "coral-common/utils/dotize";
-import { DuplicateStoryURLError } from "coral-server/errors";
+import {
+  DuplicateStoryIDError,
+  DuplicateStoryURLError,
+} from "coral-server/errors";
 import {
   GQLStoryMetadata,
   GQLStorySettings,
@@ -120,14 +123,14 @@ export interface UpsertStoryInput {
 export async function upsertStory(
   mongo: Db,
   tenantID: string,
-  { id, url }: UpsertStoryInput,
+  { id = uuid.v4(), url }: UpsertStoryInput,
   now = new Date()
 ) {
   // Create the story, optionally sourcing the id from the input, additionally
   // porting in the tenantID.
   const update: { $setOnInsert: Story } = {
     $setOnInsert: {
-      id: id ? id : uuid.v4(),
+      id,
       url,
       tenantID,
       createdAt: now,
@@ -140,25 +143,35 @@ export async function upsertStory(
     },
   };
 
-  // Perform the find and update operation to try and find and or create the
-  // story.
-  const result = await collection(mongo).findOneAndUpdate(
-    {
-      url,
-      tenantID,
-    },
-    update,
-    {
-      // Create the object if it doesn't already exist.
-      upsert: true,
+  try {
+    // Perform the find and update operation to try and find and or create the
+    // story.
+    const result = await collection(mongo).findOneAndUpdate(
+      {
+        url,
+        tenantID,
+      },
+      update,
+      {
+        // Create the object if it doesn't already exist.
+        upsert: true,
 
-      // False to return the updated document instead of the original
-      // document.
-      returnOriginal: false,
+        // False to return the updated document instead of the original
+        // document.
+        returnOriginal: false,
+      }
+    );
+
+    return result.value || null;
+  } catch (err) {
+    // Evaluate the error, if it is in regards to violating the unique index,
+    // then return a duplicate Story error.
+    if (err instanceof MongoError && err.code === 11000) {
+      throw new DuplicateStoryIDError(err, id, url);
     }
-  );
 
-  return result.value || null;
+    throw err;
+  }
 }
 
 export interface FindStoryInput {
@@ -256,7 +269,7 @@ export async function createStory(
     // Evaluate the error, if it is in regards to violating the unique index,
     // then return a duplicate Story error.
     if (err instanceof MongoError && err.code === 11000) {
-      throw new DuplicateStoryURLError(url);
+      throw new DuplicateStoryURLError(err, url, id);
     }
 
     throw err;
@@ -343,7 +356,7 @@ export async function updateStory(
     // Evaluate the error, if it is in regards to violating the unique index,
     // then return a duplicate Story error.
     if (input.url && err instanceof MongoError && err.code === 11000) {
-      throw new DuplicateStoryURLError(input.url);
+      throw new DuplicateStoryURLError(err, input.url, id);
     }
 
     throw err;
diff --git a/src/core/server/models/user/user.ts b/src/core/server/models/user/user.ts
index 42e01d959..024dcea75 100644
--- a/src/core/server/models/user/user.ts
+++ b/src/core/server/models/user/user.ts
@@ -556,7 +556,7 @@ export async function insertUser(
     await collection(mongo).insert(user);
   } catch (err) {
     // Evaluate the error, if it is in regards to violating the unique index,
-    // then return a duplicate Story error.
+    // then return a duplicate User error.
     if (err instanceof MongoError && err.code === 11000) {
       // Check if duplicate index was about the email.
       if (err.errmsg && err.errmsg.includes("tenantID_1_email_1")) {
diff --git a/src/core/server/queue/Task.ts b/src/core/server/queue/Task.ts
index 93680921b..3eeb02ea7 100644
--- a/src/core/server/queue/Task.ts
+++ b/src/core/server/queue/Task.ts
@@ -21,7 +21,7 @@ export default class Task<T, U = any> {
     jobOptions = {},
     queue,
   }: TaskOptions<T, U>) {
-    this.log = logger.child({ jobName });
+    this.log = logger.child({ jobName }, true);
     this.queue = new Queue(jobName, queue);
     this.options = {
       jobName,
@@ -70,7 +70,7 @@ export default class Task<T, U = any> {
    */
   public process() {
     this.queue.process(async (job: Job<T>) => {
-      const log = this.log.child({ jobID: job.id });
+      const log = this.log.child({ jobID: job.id }, true);
 
       log.trace("processing job from queue");
 
diff --git a/src/core/server/queue/tasks/mailer/index.ts b/src/core/server/queue/tasks/mailer/index.ts
index 8a91ffdf6..db2c2be41 100644
--- a/src/core/server/queue/tasks/mailer/index.ts
+++ b/src/core/server/queue/tasks/mailer/index.ts
@@ -38,10 +38,13 @@ export class MailerQueue {
   }
 
   public async add({ template, tenantID, message: { to } }: MailerInput) {
-    const log = logger.child({
-      jobName: JOB_NAME,
-      tenantID,
-    });
+    const log = logger.child(
+      {
+        jobName: JOB_NAME,
+        tenantID,
+      },
+      true
+    );
 
     // All email templates require the tenant in order to insert the footer, so
     // load it from the tenant cache here.
diff --git a/src/core/server/queue/tasks/mailer/processor.ts b/src/core/server/queue/tasks/mailer/processor.ts
index f423cf137..b29333b86 100644
--- a/src/core/server/queue/tasks/mailer/processor.ts
+++ b/src/core/server/queue/tasks/mailer/processor.ts
@@ -206,11 +206,14 @@ export const createJobProcessor = (options: MailProcessorOptions) => {
     // Pull the data out of the validated model.
     const { tenantID } = data;
 
-    const log = logger.child({
-      jobID: job.id,
-      jobName: JOB_NAME,
-      tenantID,
-    });
+    const log = logger.child(
+      {
+        jobID: job.id,
+        jobName: JOB_NAME,
+        tenantID,
+      },
+      true
+    );
 
     // Get the referenced tenant so we know who to send it from.
     const tenant = await tenantCache.retrieveByID(tenantID);
diff --git a/src/core/server/queue/tasks/notifier/processor.ts b/src/core/server/queue/tasks/notifier/processor.ts
index f448c4626..a40521760 100644
--- a/src/core/server/queue/tasks/notifier/processor.ts
+++ b/src/core/server/queue/tasks/notifier/processor.ts
@@ -70,11 +70,14 @@ export const createJobProcessor = ({
     const { tenantID, input } = job.data;
 
     // Create a new logger to handle logging for this job.
-    const log = logger.child({
-      jobID: job.id,
-      jobName: JOB_NAME,
-      tenantID,
-    });
+    const log = logger.child(
+      {
+        jobID: job.id,
+        jobName: JOB_NAME,
+        tenantID,
+      },
+      true
+    );
 
     log.debug("starting to handle a notify operation");
 
diff --git a/src/core/server/queue/tasks/scraper.ts b/src/core/server/queue/tasks/scraper.ts
index 9e90dace8..b2cd32e6b 100644
--- a/src/core/server/queue/tasks/scraper.ts
+++ b/src/core/server/queue/tasks/scraper.ts
@@ -24,13 +24,16 @@ const createJobProcessor = ({ mongo }: ScrapeProcessorOptions) => async (
   // Pull out the job data.
   const { storyID, storyURL, tenantID } = job.data;
 
-  const log = logger.child({
-    jobID: job.id,
-    jobName: JOB_NAME,
-    storyID,
-    storyURL,
-    tenantID,
-  });
+  const log = logger.child(
+    {
+      jobID: job.id,
+      jobName: JOB_NAME,
+      storyID,
+      storyURL,
+      tenantID,
+    },
+    true
+  );
 
   // Mark the start time.
   const startTime = now();
diff --git a/src/core/server/services/comments/index.ts b/src/core/server/services/comments/index.ts
index e14a0d00e..5387e26ce 100644
--- a/src/core/server/services/comments/index.ts
+++ b/src/core/server/services/comments/index.ts
@@ -68,13 +68,16 @@ export async function create(
   now = new Date(),
   req?: Request
 ) {
-  let log = logger.child({
-    authorID: author.id,
-    tenantID: tenant.id,
-    storyID: input.storyID,
-    parentID: input.parentID,
-    nudge,
-  });
+  let log = logger.child(
+    {
+      authorID: author.id,
+      tenantID: tenant.id,
+      storyID: input.storyID,
+      parentID: input.parentID,
+      nudge,
+    },
+    true
+  );
 
   // TODO: (wyattjoh) perform rate limiting based on the user?
 
@@ -178,7 +181,10 @@ export async function create(
   // Pull the revision out.
   const revision = getLatestRevision(comment);
 
-  log = log.child({ commentID: comment.id, status, revisionID: revision.id });
+  log = log.child(
+    { commentID: comment.id, status, revisionID: revision.id },
+    true
+  );
 
   log.trace("comment created");
 
@@ -262,7 +268,7 @@ export async function edit(
   now = new Date(),
   req?: Request
 ) {
-  let log = logger.child({ commentID: input.id, tenantID: tenant.id });
+  let log = logger.child({ commentID: input.id, tenantID: tenant.id }, true);
 
   // Get the comment that we're editing. This comment is considered stale,
   // because it wasn't involved in the atomic transaction.
@@ -345,7 +351,7 @@ export async function edit(
   // Pull the old/edited comments out of the edit result.
   const { oldComment, editedComment, newRevision } = result;
 
-  log = log.child({ revisionID: newRevision.id });
+  log = log.child({ revisionID: newRevision.id }, true);
 
   if (actions.length > 0) {
     // Insert and handle creating the actions.
diff --git a/src/core/server/services/comments/moderation/index.ts b/src/core/server/services/comments/moderation/index.ts
index c3e68de32..4e5ac0c05 100644
--- a/src/core/server/services/comments/moderation/index.ts
+++ b/src/core/server/services/comments/moderation/index.ts
@@ -34,11 +34,14 @@ const moderate = (
   // TODO: wrap these operations in a transaction?
 
   // Create the logger.
-  const log = logger.child({
-    ...input,
-    tenantID: tenant.id,
-    newStatus: status,
-  });
+  const log = logger.child(
+    {
+      ...input,
+      tenantID: tenant.id,
+      newStatus: status,
+    },
+    true
+  );
 
   // Update the Comment's status.
   const result = await updateCommentStatus(
diff --git a/src/core/server/services/comments/pipeline/phases/spam.ts b/src/core/server/services/comments/pipeline/phases/spam.ts
index 71f33fdbe..558221ab7 100644
--- a/src/core/server/services/comments/pipeline/phases/spam.ts
+++ b/src/core/server/services/comments/pipeline/phases/spam.ts
@@ -22,9 +22,12 @@ export const spam: IntermediateModerationPhase = async ({
 }): Promise<IntermediatePhaseResult | void> => {
   const integration = tenant.integrations.akismet;
 
-  const log = logger.child({
-    tenantID: tenant.id,
-  });
+  const log = logger.child(
+    {
+      tenantID: tenant.id,
+    },
+    true
+  );
 
   // We can only check for spam if this comment originated from a graphql
   // request via an HTTP call.
diff --git a/src/core/server/services/comments/pipeline/phases/toxic.ts b/src/core/server/services/comments/pipeline/phases/toxic.ts
index 03fc23d87..4320381ad 100644
--- a/src/core/server/services/comments/pipeline/phases/toxic.ts
+++ b/src/core/server/services/comments/pipeline/phases/toxic.ts
@@ -32,7 +32,7 @@ export const toxic: IntermediateModerationPhase = async ({
     return;
   }
 
-  const log = logger.child({ tenantID: tenant.id });
+  const log = logger.child({ tenantID: tenant.id }, true);
 
   const integration = tenant.integrations.perspective;
 
diff --git a/src/core/server/services/notifications/context.ts b/src/core/server/services/notifications/context.ts
index 58da5d814..2e5d5e677 100644
--- a/src/core/server/services/notifications/context.ts
+++ b/src/core/server/services/notifications/context.ts
@@ -98,7 +98,7 @@ export default class NotificationContext {
     this.now = now;
     this.config = config;
     this.signingConfig = signingConfig;
-    this.log = log.child({ tenantID: tenant.id });
+    this.log = log.child({ tenantID: tenant.id }, true);
   }
 
   /**
diff --git a/src/core/server/services/queries/cache.ts b/src/core/server/services/queries/cache.ts
index 1b8b888dc..d979d5b25 100644
--- a/src/core/server/services/queries/cache.ts
+++ b/src/core/server/services/queries/cache.ts
@@ -2,7 +2,7 @@ import DataLoader from "dataloader";
 import LRU from "lru-cache";
 import { Db } from "mongodb";
 
-import { loadPersistedQueries } from "coral-server/graph/tenant/persisted";
+import { loadPersistedQueries } from "coral-server/graph/common/persisted";
 import logger from "coral-server/logger";
 import {
   getQueries,
diff --git a/src/core/server/services/stories/index.ts b/src/core/server/services/stories/index.ts
index 2759ee487..148115c8a 100644
--- a/src/core/server/services/stories/index.ts
+++ b/src/core/server/services/stories/index.ts
@@ -101,10 +101,13 @@ export async function remove(
   includeComments: boolean = false
 ) {
   // Create a logger for this function.
-  const log = logger.child({
-    storyID,
-    includeComments,
-  });
+  const log = logger.child(
+    {
+      storyID,
+      includeComments,
+    },
+    true
+  );
 
   log.debug("starting to remove story");
 
@@ -254,10 +257,13 @@ export async function merge(
   sourceIDs: string[]
 ) {
   // Create a logger for this operation.
-  const log = logger.child({
-    destinationID,
-    sourceIDs,
-  });
+  const log = logger.child(
+    {
+      destinationID,
+      sourceIDs,
+    },
+    true
+  );
 
   if (sourceIDs.length === 0) {
     log.warn("cannot merge from 0 stories");
diff --git a/src/core/server/services/stories/scraper/index.ts b/src/core/server/services/stories/scraper/index.ts
index 558b9a0b8..b3d87b1d4 100644
--- a/src/core/server/services/stories/scraper/index.ts
+++ b/src/core/server/services/stories/scraper/index.ts
@@ -31,7 +31,7 @@ class Scraper {
 
   constructor(rules: Rule[]) {
     this.rules = rules;
-    this.log = logger.child({ taskName: "scraper" });
+    this.log = logger.child({ taskName: "scraper" }, true);
   }
 
   public async scrape(
@@ -40,7 +40,7 @@ class Scraper {
   ): Promise<GQLStoryMetadata | null> {
     // Grab the page HTML.
 
-    const log = this.log.child({ storyURL: url });
+    const log = this.log.child({ storyURL: url }, true);
 
     const options: RequestInit = {
       headers: {
diff --git a/src/core/server/services/tenant/index.ts b/src/core/server/services/tenant/index.ts
index b0eb33d66..eea30f6b1 100644
--- a/src/core/server/services/tenant/index.ts
+++ b/src/core/server/services/tenant/index.ts
@@ -89,7 +89,7 @@ export async function install(
 
   // TODO: (wyattjoh) perform any pending migrations.
 
-  logger.info({ tenant: input }, "installing tenant");
+  logger.info("installing tenant");
 
   // Create the Tenant.
   const tenant = await createTenant(mongo, i18n, input, now);
@@ -97,7 +97,7 @@ export async function install(
   // Update the tenant cache.
   await cache.update(redis, tenant);
 
-  logger.info({ tenant }, "a tenant has been installed");
+  logger.info({ tenantID: tenant.id }, "a tenant has been installed");
 
   return tenant;
 }
diff --git a/src/core/server/types/express.ts b/src/core/server/types/express.ts
index 20e089f81..4f9559b1a 100644
--- a/src/core/server/types/express.ts
+++ b/src/core/server/types/express.ts
@@ -1,6 +1,7 @@
 import { NextFunction, Request as ExpressRequest, Response } from "express";
 
 import { Logger } from "coral-server/logger";
+import { PersistedQuery } from "coral-server/models/queries";
 import { Tenant } from "coral-server/models/tenant";
 import { User } from "coral-server/models/user";
 import TenantCache from "coral-server/services/tenant/cache";
@@ -12,6 +13,7 @@ export interface CoralRequest {
     tenant: TenantCache;
   };
   tenant?: Tenant;
+  persisted?: PersistedQuery;
   logger: Logger;
 }
 
@@ -25,3 +27,10 @@ export type RequestHandler = (
   res: Response,
   next: NextFunction
 ) => void;
+
+export type ErrorRequestHandler = (
+  err: Error,
+  req: Request,
+  res: Response,
+  next: NextFunction
+) => void;