Remove use of Pino child loggers (fixes experiment refresh bug)

packages/back-end/src/jobs/updateExperimentResults.ts

@@ -25,7 +25,7 @@ import { analyzeExperimentResults } from "../services/stats";
 import { DEFAULT_SEQUENTIAL_TESTING_TUNING_PARAMETER } from "../constants/stats";
 import { getReportVariations } from "../services/reports";
 import { findOrganizationById } from "../models/OrganizationModel";
-import { childLogger } from "../util/logger";
+import { logger } from "../util/logger";
 import {
   ExperimentSnapshotInterface,
   ExperimentSnapshotSettings,
@@ -116,11 +116,6 @@ async function updateSingleExperiment(job: UpdateSingleExpJob) {
   const orgId = job.attrs.data?.organization;
   if (!experimentId || !orgId) return;
 
-  const log = childLogger({
-    cron: "updateSingleExperiment",
-    experimentId,
-  });
-
   const experiment = await getExperimentById(orgId, experimentId);
   if (!experiment) return;
 
@@ -139,7 +134,7 @@ async function updateSingleExperiment(job: UpdateSingleExpJob) {
     : false;
 
   try {
-    log.info("Start Refreshing Results");
+    logger.info("Start Refreshing Results for expeirment " + experimentId);
     const datasource = await getDataSourceById(
       experiment.datasource || "",
       experiment.organization
@@ -230,13 +225,11 @@ async function updateSingleExperiment(job: UpdateSingleExpJob) {
       setTimeout(check, 2000);
     });
 
-    log.info("Success");
-
     if (lastSnapshot) {
       await sendSignificanceEmail(experiment, lastSnapshot, currentSnapshot);
     }
   } catch (e) {
-    log.error("Failure - " + e.message);
+    logger.error(e, "Failed to update experiment: " + experimentId);
     // If we failed to update the experiment, turn off auto-updating for the future
     try {
       await updateExperiment({
@@ -249,7 +242,7 @@ async function updateSingleExperiment(job: UpdateSingleExpJob) {
       });
       // TODO: email user and let them know it failed
     } catch (e) {
-      log.error("Failed to turn off autoSnapshots - " + e.message);
+      logger.error(e, "Failed to turn off autoSnapshots: " + experimentId);
     }
   }
 }
@@ -259,11 +252,6 @@ async function sendSignificanceEmail(
   lastSnapshot: ExperimentSnapshotInterface,
   currentSnapshot: ExperimentSnapshotInterface
 ) {
-  const log = childLogger({
-    cron: "sendSignificanceEmail",
-    experimentId: experiment.id,
-  });
-
   // If email is not configured, there's nothing else to do
   if (!isEmailEnabled()) {
     return;
@@ -331,11 +319,6 @@ async function sendSignificanceEmail(
 
     if (experimentChanges.length) {
       // send an email to any subscribers on this test:
-      log.info(
-        "Significant change - detected " +
-          experimentChanges.length +
-          " significant changes"
-      );
       const watchers = await getExperimentWatchers(
         experiment.id,
         experiment.organization
@@ -350,6 +333,6 @@ async function sendSignificanceEmail(
       );
     }
   } catch (e) {
-    log.error(e.message);
+    logger.error(e, "Failed to send significance email");
   }
 }

packages/back-end/src/jobs/updateMetrics.ts

@@ -7,7 +7,7 @@ import {
 import { getMetricById } from "../models/MetricModel";
 import { METRIC_REFRESH_FREQUENCY } from "../util/secrets";
 import { OrganizationSettings } from "../../types/organization";
-import { childLogger } from "../util/logger";
+import { logger } from "../util/logger";
 
 const QUEUE_METRIC_UPDATES = "queueMetricUpdates";
 
@@ -81,31 +81,23 @@ async function updateSingleMetric(job: UpdateSingleMetricJob) {
   const orgId = job.attrs.data?.orgId;
   const orgSettings = job.attrs.data?.orgSettings;
 
-  const log = childLogger({
-    cron: "updateSingleMetric",
-    metricId,
-    orgId,
-  });
-
-  if (!metricId || !orgId) {
-    log.error("Error getting metricId from job");
-    return false;
-  }
-  const metric = await getMetricById(metricId, orgId, true);
+  try {
+    if (!metricId || !orgId) {
+      throw new Error("Error getting metricId or orgId from job");
+    }
+    const metric = await getMetricById(metricId, orgId, true);
 
-  if (!metric) {
-    log.error("Error getting metric to refresh: " + metricId);
-    return false;
-  }
+    if (!metric) {
+      throw new Error("Error getting metric to refresh: " + metricId);
+    }
 
-  try {
-    log.info("Start Refreshing Metric: " + metricId);
+    logger.info("Start Refreshing Metric: " + metricId);
     const days =
       orgSettings?.metricAnalysisDays || DEFAULT_METRIC_ANALYSIS_DAYS;
     await refreshMetric(metric, orgId, days);
+    logger.info("Successfully Refreshed Metric: " + metricId);
   } catch (e) {
-    log.error("Error refreshing metric: " + e.message);
+    logger.error(e, "Error refreshing metric");
+    return false;
   }
-
-  log.info("Success");
 }

packages/back-end/src/jobs/updateScheduledFeatures.ts

@@ -6,7 +6,7 @@ import {
 } from "../models/FeatureModel";
 import { getNextScheduledUpdate } from "../services/features";
 import { getOrganizationById } from "../services/organizations";
-import { childLogger } from "../util/logger";
+import { logger } from "../util/logger";
 
 type UpdateSingleFeatureJob = Job<{
   featureId: string;
@@ -66,11 +66,6 @@ async function updateSingleFeature(job: UpdateSingleFeatureJob) {
   const organization = job.attrs.data?.organization;
   if (!featureId) return;
 
-  const log = childLogger({
-    cron: "updateSingleFeature",
-    featureId,
-  });
-
   const org = await getOrganizationById(organization);
   if (!org) return;
 
@@ -88,6 +83,6 @@ async function updateSingleFeature(job: UpdateSingleFeatureJob) {
       nextScheduledUpdate: nextScheduledUpdate,
     });
   } catch (e) {
-    log.error("Failure - " + e.message);
+    logger.error(e, "Failed updating feature " + featureId);
   }
 }

packages/back-end/src/util/logger.ts

@@ -85,8 +85,3 @@ export const logger: BaseLogger = {
     httpLogger.logger.warn(...args);
   },
 };
-
-/**
- * pino's logger.child function
- */
-export const childLogger = httpLogger.logger.child;