[CON-389] Remove useless logs and move semi-useful logs to be debug (…

…#4174)

creator-node/src/apiHelpers.ts

@@ -7,7 +7,6 @@ import { tracing } from './tracer'
 import config from './config'
 
 import {
-  requestNotExcludedFromLogging,
   getDuration,
   createChildLogger,
   logger as genericLogger
@@ -106,16 +105,12 @@ export const sendResponse = (
     statusCode: resp.statusCode
   }) as Logger
 
-  if (resp.statusCode === 200) {
-    if (requestNotExcludedFromLogging(req.originalUrl)) {
-      logger.info('Success')
-    }
-  } else {
+  if (resp.statusCode !== 200) {
     logger = createChildLogger(logger, {
       errorMessage: resp.object.error
     }) as Logger
     if (req && req.body) {
-      logger.info(
+      logger.error(
         'Error processing request:',
         resp.object.error,
         '|| Request Body:',
@@ -124,7 +119,7 @@ export const sendResponse = (
         req.query
       )
     } else {
-      logger.info('Error processing request:', resp.object.error)
+      logger.error('Error processing request:', resp.object.error)
     }
   }
 
@@ -147,23 +142,19 @@ export const sendResponseWithHeartbeatTerminator = (
     statusCode: resp.statusCode
   }) as Logger
 
-  if (resp.statusCode === 200) {
-    if (requestNotExcludedFromLogging(req.originalUrl)) {
-      logger.info('Success')
-    }
-  } else {
+  if (resp.statusCode !== 200) {
     logger = createChildLogger(logger, {
       errorMessage: resp.object.error
     }) as Logger
     if (req && req.body) {
-      logger.info(
+      logger.error(
         'Error processing request:',
         resp.object.error,
         '|| Request Body:',
         req.body
       )
     } else {
-      logger.info('Error processing request:', resp.object.error)
+      logger.error('Error processing request:', resp.object.error)
     }
 
     // Converts the error object into an object that JSON.stringify can parse

creator-node/src/app.ts

@@ -205,7 +205,7 @@ export const initializeApp = (port: number, serviceRegistry: any) => {
   app.set('trust proxy', true)
 
   const server = app.listen(port, () =>
-    logger.info(`Listening on port ${port}...`)
+    logger.debug(`Listening on port ${port}...`)
   )
 
   // Increase from 2min default to accommodate long-lived requests.

creator-node/src/logging.js

@@ -93,7 +93,7 @@ function loggingMiddleware(req, res, next) {
   req.logger = logger.child(req.logContext)
 
   if (requestNotExcludedFromLogging(req.originalUrl)) {
-    req.logger.info('Begin processing request')
+    req.logger.debug('Begin processing request')
   }
   next()
 }
@@ -124,6 +124,26 @@ function getDuration({ startTime }) {
   return durationMs
 }
 
+/**
+ * Prints the debug message with the duration
+ * @param {Object} logger
+ * @param {number} startTime the start time
+ * @param {string} msg the message to print
+ */
+function logDebugWithDuration(
+  { logger, startTime },
+  msg,
+  durationKey = 'duration'
+) {
+  const durationMs = getDuration({ startTime })
+
+  if (durationMs) {
+    logger.debug({ [durationKey]: durationMs }, msg)
+  } else {
+    logger.debug(msg)
+  }
+}
+
 /**
  * Prints the log message with the duration
  * @param {Object} logger
@@ -168,6 +188,7 @@ module.exports = {
   getStartTime,
   getDuration,
   createChildLogger,
+  logDebugWithDuration,
   logInfoWithDuration,
   logErrorWithDuration
 }

creator-node/src/services/stateMachineManager/makeOnCompleteCallback.ts

@@ -81,7 +81,7 @@ function makeOnCompleteCallback(
     // Bull serializes the job result into redis, so we have to deserialize it into JSON
     let jobResult: AnyDecoratedJobReturnValue
     try {
-      logger.info(`Job successfully completed. Parsing result`)
+      logger.debug(`Job processor successfully completed. Parsing result`)
       if (typeof returnvalue === 'string' || returnvalue instanceof String) {
         jobResult = JSON.parse(returnvalue as string) || {}
       } else {
@@ -147,7 +147,7 @@ const enqueueJobs = async (
   triggeredByJobId: string,
   logger: Logger
 ) => {
-  logger.info(
+  logger.debug(
     `Attempting to add ${jobs?.length} jobs in bulk to queue ${queueNameToAddTo}`
   )
 

creator-node/src/services/stateMachineManager/stateMachineUtils.js

@@ -322,14 +322,14 @@ const makeQueue = ({
 const _registerQueueEvents = (worker, queueLogger) => {
   worker.on('active', (job, _prev) => {
     const logger = createChildLogger(queueLogger, { jobId: job.id })
-    logger.info('Job active')
+    logger.debug('Job active')
   })
   worker.on('error', (error) => {
     queueLogger.error(`Job error - ${error}`)
   })
   worker.on('stalled', (jobId, _prev) => {
     const logger = createChildLogger(queueLogger, { jobId })
-    logger.info('Job stalled')
+    logger.debug('Job stalled')
   })
 }
 

creator-node/src/services/stateMachineManager/stateReconciliation/issueSyncRequest.jobProcessor.ts

@@ -128,7 +128,9 @@ async function issueSyncRequest({
       : MAX_ISSUE_RECURRING_SYNC_JOB_ATTEMPTS
   if (!_.isEmpty(additionalSync)) {
     if (attemptNumber < maxRetries) {
-      logger.info(`Retrying issue-sync-request after attempt #${attemptNumber}`)
+      logger.debug(
+        `Retrying issue-sync-request after attempt #${attemptNumber}`
+      )
       const queueName =
         additionalSync?.syncType === SyncType.Manual
           ? QUEUE_NAMES.MANUAL_SYNC
@@ -138,7 +140,7 @@ async function issueSyncRequest({
         attemptNumber: attemptNumber + 1
       })
     } else {
-      logger.info(
+      logger.warn(
         `Gave up retrying issue-sync-request (type: ${additionalSync?.syncType}) after ${attemptNumber} failed attempts`
       )
     }

creator-node/src/services/stateMachineManager/stateReconciliation/stateReconciliationUtils.js

@@ -53,7 +53,7 @@ const getNewOrExistingSyncReq = async ({
       immediate
     )
   if (duplicateSyncJobInfo) {
-    logger.info(
+    logger.error(
       `getNewOrExistingSyncReq() Failure - a sync of type ${syncType} is already waiting for user wallet ${userWallet} against secondary ${secondaryEndpoint}`
     )
 

creator-node/src/services/sync/syncUtil.ts

@@ -152,7 +152,7 @@ export async function fetchExportFromNode({
     }
   }
 
-  logger.info('Export successful')
+  logger.debug('Export successful')
 
   return {
     fetchedCNodeUser

creator-node/src/utils/cidUtils.ts

@@ -134,7 +134,7 @@ export async function findCIDInNetwork(
             throw new Error('CID does not match what is expected to be')
           }
 
-          logger.info(
+          logger.debug(
             `Successfully fetched CID=${cid} file=${filePath} from node ${endpoint}`
           )
 

creator-node/src/utils/fsUtils.ts

@@ -78,7 +78,7 @@ export async function validateStateForImageDirCIDAndReturnFileUUID(
   if (!imageDirCID) {
     return null
   }
-  req.logger.info(
+  req.logger.debug(
     `Beginning validateStateForImageDirCIDAndReturnFileUUID for imageDirCID ${imageDirCID}`
   )
 
@@ -125,7 +125,7 @@ export async function validateStateForImageDirCIDAndReturnFileUUID(
     })
   )
 
-  req.logger.info(
+  req.logger.debug(
     `Completed validateStateForImageDirCIDAndReturnFileUUID for imageDirCID ${imageDirCID}`
   )
   return dirFile.fileUUID

creator-node/src/utils/validateAudiusUserMetadata.ts

@@ -45,7 +45,7 @@ export const validateMetadata = (req: Request, metadataJSON: MetadataJson) => {
     return false
   } else if (!validateAssociatedWallets(metadataJSON)) {
     const reqWithLogger = req as RequestWithLogger
-    reqWithLogger.logger.info('Associated Wallets do not match signatures')
+    reqWithLogger.logger.warn('Associated Wallets do not match signatures')
     return false
   }
 

creator-node/test/issueSyncRequest.jobProcessor.test.js

@@ -62,6 +62,7 @@ describe('test issueSyncRequest job processor', function () {
     config.set('creatorNodeEndpoint', primary)
     logger = {
       info: sandbox.stub(),
+      debug: sandbox.stub(),
       warn: sandbox.stub(),
       error: sandbox.stub()
     }