refactor: Migrate to pino logger

Replaces Winston/Morgan loggers with pino and pino-http.

packages/backend/env/.env

@@ -1,7 +1,7 @@
 # Logging
-LOG_REQUESTS=true
+LOG_REQUESTS=false
 LOG_LEVEL=info
-LOG_FORMAT=default
+LOG_FORMAT=pretty
 LOG_TIMESTAMPS=true
 
 # Server

packages/backend/env/.env.development

@@ -1,5 +1,5 @@
 # Logging
-LOG_LEVEL=silly
+LOG_LEVEL=trace
 
 # Server
 HOST=localhost

packages/backend/env/.env.test

@@ -1,5 +1,5 @@
-# Logging
-LOG_LEVEL=silly
-
-# Server
-HOST=localhost
+# Logging
+LOG_LEVEL=debug
+
+# Server
+HOST=localhost

packages/backend/package.json

@@ -27,7 +27,6 @@
     "@elastic/elasticsearch": "7.13.0",
     "@octokit/graphql": "4.8.0",
     "@octokit/rest": "18.12.0",
-    "@types/turndown": "5.0.1",
     "apollo-server-core": "3.6.7",
     "apollo-server-express": "3.6.7",
     "aws-sdk": "2.1113.0",
@@ -59,7 +58,6 @@
     "luxon": "2.3.1",
     "mime": "3.0.0",
     "module-alias": "2.2.2",
-    "morgan": "1.10.0",
     "nanoid": "3.3.3",
     "node-cache": "5.1.2",
     "node-html-parser": "3.3.6",
@@ -76,8 +74,7 @@
     "tweetnacl": "1.0.3",
     "tweetnacl-util": "0.15.1",
     "type-graphql": "1.1.1",
-    "typedi": "0.10.0",
-    "winston": "3.5.1"
+    "typedi": "0.10.0"
   },
   "devDependencies": {
     "@types/better-queue": "3.8.3",
@@ -96,11 +93,11 @@
     "@types/luxon": "2.3.1",
     "@types/mime": "2.0.3",
     "@types/module-alias": "2.0.1",
-    "@types/morgan": "1.9.3",
     "@types/node": "16.11.26",
     "@types/parsimmon": "1.10.6",
     "@types/supertest": "2.0.12",
     "@types/tmp": "0.2.3",
+    "@types/turndown": "5.0.1",
     "@types/validator": "13.7.2",
     "@typescript-eslint/eslint-plugin": "5.19.0",
     "@typescript-eslint/parser": "5.19.0",

packages/backend/src/controllers/avatars.v1.ts

@@ -14,20 +14,22 @@
  * limitations under the License.
  */
 
-import logger from '@iex/shared/logger';
+import { getLogger } from '@iex/shared/logger';
 import { AWSError } from 'aws-sdk';
 import { Response, Request } from 'express';
 
 import { streamFromS3 } from '../lib/storage';
 import { getType } from '../shared/mime';
 
+const logger = getLogger('avatars.v1');
+
 /**
  * GET /avatars/:key?content-type=
  */
 export const getAvatar = async (req: Request, res: Response): Promise<void> => {
   const key = req.params.key;
   const path = `avatars/${key}`;
-  logger.debug(`[AVATARS.V1] Attempting to load avatar: ${path}`);
+  logger.debug(`Attempting to load avatar: ${path}`);
 
   const readable = await streamFromS3(path);
   readable.on('error', (error: AWSError) => {

packages/backend/src/controllers/drafts.v1.ts

@@ -14,18 +14,20 @@
  * limitations under the License.
  */
 
-import logger from '@iex/shared/logger';
+import { getLogger } from '@iex/shared/logger';
 import { AWSError } from 'aws-sdk';
 import { Response, Request } from 'express';
 
 import { streamFromS3 } from '../lib/storage';
 
+const logger = getLogger('drafts.v1');
+
 /**
  * GET /drafts/:draftKey/assets/:attachmentKey?content-type=
  */
 export const getDraftAttachment = async (req: Request, res: Response): Promise<void> => {
   const draftKey = `drafts/${req.params.draftKey}/files/${req.params.attachmentKey}`;
-  logger.debug(`[DRAFTS.V1] Attempting to load draft attachment: ${draftKey}, ${req.params.attachmentKey}`);
+  logger.debug(`Attempting to load draft attachment: ${draftKey}, ${req.params.attachmentKey}`);
 
   const readable = await streamFromS3(draftKey);
   readable.on('error', (error: AWSError) => {

packages/backend/src/controllers/graphql.v1.ts

@@ -14,7 +14,7 @@
  * limitations under the License.
  */
 
-import logger from '@iex/shared/logger';
+import { getLogger } from '@iex/shared/logger';
 import {
   ApolloServerPluginLandingPageLocalDefault,
   ApolloServerPluginLandingPageProductionDefault
@@ -24,14 +24,16 @@ import { Container } from 'typedi';
 
 import { schema } from '../lib/graphql';
 
+const logger = getLogger('graphql.v1');
+
 const apolloConfig: ApolloServerExpressConfig = {
   schema,
   context: ({ req }) => {
     const requestId = req.id;
 
     // Scoped container
-    logger.silly('[GRAPHQL.V1] Creating Container ' + requestId);
-    const container = Container.of(requestId);
+    logger.trace('Creating Container ' + requestId);
+    const container = Container.of(requestId as string);
 
     const context = {
       container,
@@ -51,7 +53,7 @@ const apolloConfig: ApolloServerExpressConfig = {
         return {
           async willSendResponse(requestContext) {
             // Remove the request's scoped container
-            logger.silly('[GRAPHQL.V1] Terminating Container ' + requestContext.context.requestId);
+            logger.trace('Terminating Container ' + requestContext.context.requestId);
             Container.reset(requestContext.context.requestId);
           }
         };

packages/backend/src/controllers/insights.v1.ts

@@ -14,21 +14,23 @@
  * limitations under the License.
  */
 
-import logger from '@iex/shared/logger';
+import { getLogger } from '@iex/shared/logger';
 import { AWSError } from 'aws-sdk';
 import { Response, Request } from 'express';
 
 import { getFromS3, headFromS3 } from '../lib/storage';
 import { getType } from '../shared/mime';
 
+const logger = getLogger('insights.v1');
+
 /**
  * HEAD /insights/:namespace/:name/assets/:filepath
  */
 export const headInsightFile = async (req: Request, res: Response): Promise<void> => {
   const filePath = req.params.filepath + req.params[0];
   const key = `insights/${req.params.namespace}/${req.params.name}/files/${filePath}`;
 
-  logger.debug(`[INSIGHTS.V1] Attempting to HEAD insight attachment: ${filePath}`);
+  logger.debug(`Attempting to HEAD insight attachment: ${filePath}`);
 
   const headObject = await headFromS3(key);
 
@@ -53,7 +55,7 @@ export const getInsightFile = async (req: Request, res: Response): Promise<void>
   const filePath = req.params.filepath + req.params[0];
   const key = `insights/${req.params.namespace}/${req.params.name}/files/${filePath}`;
 
-  logger.debug(`[INSIGHTS.V1] Attempting to load insight attachment: ${filePath}`);
+  logger.debug(`Attempting to load insight attachment: ${filePath}`);
 
   const range = Array.isArray(req.headers['range']) ? req.headers['range'][0] : req.headers['range'];
 

packages/backend/src/controllers/webhook.v1.ts

@@ -17,13 +17,15 @@
 import { IncomingHttpHeaders } from 'http';
 
 import { RepositoryType } from '@iex/models/repository-type';
-import logger from '@iex/shared/logger';
+import { getLogger } from '@iex/shared/logger';
 import { Request, Response } from 'express';
 
 import { defaultElasticsearchClient, ElasticIndex } from '../lib/elasticsearch';
 import insightQueue from '../lib/insight-queue';
 import { InsightSyncTask } from '../models/tasks';
 
+const logger = getLogger('webhook.v1');
+
 type Webhook = any & { headers: IncomingHttpHeaders };
 
 /**

packages/backend/src/environment.ts

@@ -14,7 +14,7 @@
  * limitations under the License.
  */
 
-import logger from '@iex/shared/logger';
+import { getLogger, initializeLogger } from '@iex/shared/logger';
 import * as dotenv from 'dotenv-flow';
 import fs from 'fs-extra';
 
@@ -23,7 +23,7 @@ try {
   const packageJson = fs.readJsonSync(__dirname + `/../../../../package.json`);
   process.env.IEX_VERSION = packageJson.version;
 } catch {
-  logger.error('[ENV] Error loading package.json');
+  getLogger('environment').error('Error loading package.json');
   process.env.IEX_VERSION = 'unknown';
 }
 
@@ -39,7 +39,13 @@ if (result.error) {
   throw result.error;
 }
 
+// Initialize logger after loading environment variables
+initializeLogger();
+
+getLogger('environment').info(`NODE_ENV: ${process.env.NODE_ENV}`);
+
 // Configuration validation checks
+// eslint-disable-next-line no-constant-condition
 if (process.env.GITHUB_USE_WEBHOOK === 'true' && process.env.PUBLIC_URL === '') {
-  logger.error('[ENV] Configuration Error: PUBLIC_URL must be set when GITHUB_USE_WEBHOOK is true');
+  getLogger('environment').error('Configuration Error: PUBLIC_URL must be set when GITHUB_USE_WEBHOOK is true');
 }

packages/backend/src/index.ts

@@ -35,8 +35,10 @@ import pRetry from 'p-retry';
 import { bootstrap, defaultKnex } from './lib/db';
 import { deployMappings } from './lib/elasticsearch';
 import { createServer } from './server';
-import logger from '@iex/shared/logger';
 import { syncExampleInsights } from './lib/init';
+import { getLogger } from '@iex/shared/logger';
+
+const logger = getLogger('index');
 
 // Safeguard to prevent the application from crashing.
 // It would be better to catch any promise rejections and handle directly
@@ -52,28 +54,28 @@ process.on('uncaughtException', (uncaughtException) => {
 
 const startup = async (): Promise<Server> => {
   // Deploy Elasticsearch Index mappings
-  logger.debug('[INDEX] Deploying elasticsearch indices');
+  logger.debug('Deploying elasticsearch indices');
   await pRetry(() => deployMappings(), {
     retries: 5,
     factor: 3.86,
     onFailedAttempt: (error) => {
-      logger.warn(`[INDEX] Deploying elasticsearch indices failed (attempt ${error.attemptNumber})`);
+      logger.warn(`Deploying elasticsearch indices failed (attempt ${error.attemptNumber})`);
     }
   });
 
   // Create database pool & apply any schema migrations
-  logger.debug('[INDEX] Bootstrapping database');
+  logger.debug('Bootstrapping database');
   await pRetry(() => bootstrap(defaultKnex), {
     retries: 5,
     factor: 3.86,
     onFailedAttempt: (error) => {
-      logger.warn(`[INDEX] Bootstrapping database failed (attempt ${error.attemptNumber})`);
+      logger.warn(`Bootstrapping database failed (attempt ${error.attemptNumber})`);
       logger.warn(error);
     }
   });
 
   // Start Express server
-  logger.debug('[INDEX] Starting Express server');
+  logger.debug('Starting Express server');
   const app = await createServer();
   const server = app.listen(app.get('port'), () => {
     logger.info(`IEX Server started in ${app.get('env')} mode on port: ${app.get('port')}`);

packages/backend/src/lib/backends/base.sync.ts

@@ -15,7 +15,7 @@
  */
 
 import { IndexedInsight } from '@iex/models/indexed/indexed-insight';
-import logger from '@iex/shared/logger';
+import { getLogger } from '@iex/shared/logger';
 
 import { defaultElasticsearchClient, ElasticIndex } from '../../lib/elasticsearch';
 import { DbInsight } from '../../models/insight';
@@ -24,6 +24,8 @@ import { InsightSyncTask } from '../../models/tasks';
 import { ActivityService } from '../../services/activity.service';
 import { InsightService } from '../../services/insight.service';
 
+const logger = getLogger('base.sync');
+
 export const THUMBNAIL_EXTENSIONS = ['.png', '.jpg', '.jpeg', '.gif', '.svg'];
 export const THUMBNAIL_LOCATIONS = ['thumbnail', '.iex/thumbnail'].flatMap((prefix) =>
   THUMBNAIL_EXTENSIONS.map((extension) => prefix + extension)
@@ -58,7 +60,7 @@ export abstract class BaseSync {
     const documentType = insight.itemType;
     const index = ElasticIndex.INSIGHTS;
 
-    logger.info(`[BASE_SYNC] Publishing ${documentType} to Elasticsearch: ${insight.fullName}`);
+    logger.info(`Publishing ${documentType} to Elasticsearch: ${insight.fullName}`);
     logger.debug(JSON.stringify(insight, null, 2));
 
     try {
@@ -73,9 +75,9 @@ export abstract class BaseSync {
       });
 
       logger.debug(JSON.stringify(result));
-      logger.info(`[BASE_SYNC] Successfully published ${documentType}: ${insight.fullName}`);
+      logger.info(`Successfully published ${documentType}: ${insight.fullName}`);
     } catch (error: any) {
-      logger.error(`[BASE_SYNC] Error publishing ${documentType} to Elasticsearch`);
+      logger.error(`Error publishing ${documentType} to Elasticsearch`);
       logger.error(error);
       throw error;
     }
@@ -92,29 +94,29 @@ export abstract class BaseSync {
     let existingDbInsight = await DbInsight.query().where('externalId', externalId).first();
 
     if (existingDbInsight != undefined) {
-      logger.silly('[BASE_SYNC] Insight does exist in database');
+      logger.trace('Insight does exist in database');
       await existingDbInsight.$query().patch({
         insightName: insight.fullName,
         itemType: insight.itemType,
         deletedAt: null
       });
     } else {
-      logger.silly('[BASE_SYNC] Insight does not exist in database');
+      logger.trace('Insight does not exist in database');
 
       // Check to see if the fullName already exists, but with a different externalID
       existingDbInsight = await DbInsight.query().where('insightName', insight.fullName).first();
 
       if (existingDbInsight != undefined) {
         // Assume the repo was deleted and recreated, and just update the external ID
         // (We've already checked to ensure the external ID is unique)
-        logger.silly('[BASE_SYNC] Insight exists in database, but with a different externalId');
+        logger.trace('Insight exists in database, but with a different externalId');
         await existingDbInsight.$query().patch({
           externalId,
           itemType: insight.itemType,
           deletedAt: null
         });
       } else {
-        logger.silly('[BASE_SYNC] Insight does not exist in database');
+        logger.trace('Insight does not exist in database');
         existingDbInsight = await DbInsight.query().insert({
           externalId,
           insightName: insight.fullName,
@@ -128,7 +130,7 @@ export abstract class BaseSync {
       }
     }
 
-    logger.silly(JSON.stringify(existingDbInsight, null, 2));
+    logger.trace(JSON.stringify(existingDbInsight, null, 2));
 
     // Use the Database ID as the document ID in Elasticsearch
     insight.insightId = existingDbInsight.insightId!;