Fix error logging
authorChocobozzz <me@florianbigard.com>
Mon, 26 Mar 2018 13:54:13 +0000 (15:54 +0200)
committerChocobozzz <me@florianbigard.com>
Mon, 26 Mar 2018 14:04:14 +0000 (16:04 +0200)
24 files changed:
server.ts
server/controllers/api/server/follows.ts
server/controllers/api/videos/blacklist.ts
server/controllers/api/videos/channel.ts
server/helpers/database-utils.ts
server/helpers/ffmpeg-utils.ts
server/helpers/logger.ts
server/helpers/peertube-crypto.ts
server/helpers/utils.ts
server/initializers/installer.ts
server/initializers/migrator.ts
server/lib/activitypub/actor.ts
server/lib/activitypub/process/process-update.ts
server/lib/activitypub/video-comments.ts
server/lib/activitypub/videos.ts
server/lib/emailer.ts
server/lib/job-queue/job-queue.ts
server/lib/redis.ts
server/lib/schedulers/bad-actor-follow-scheduler.ts
server/middlewares/activitypub.ts
server/middlewares/validators/videos.ts
server/models/activitypub/actor-follow.ts
server/models/oauth/oauth-token.ts
server/models/video/video.ts

index 56a4a0c443f8129e317c6ff3262254841e12e83c..f6794b89783536bf044e58858a335d3370e4ceb2 100644 (file)
--- a/server.ts
+++ b/server.ts
@@ -27,13 +27,21 @@ const app = express()
 // ----------- Core checker -----------
 import { checkMissedConfig, checkFFmpeg, checkConfig } from './server/initializers/checker'
 
+// Do not use barrels because we don't want to load all modules here (we need to initialize database first)
+import { logger } from './server/helpers/logger'
+import { ACCEPT_HEADERS, API_VERSION, CONFIG, STATIC_PATHS } from './server/initializers/constants'
+
 const missed = checkMissedConfig()
 if (missed.length !== 0) {
-  throw new Error('Your configuration files miss keys: ' + missed)
+  logger.error('Your configuration files miss keys: ' + missed)
+  process.exit(-1)
 }
 
-import { ACCEPT_HEADERS, API_VERSION, CONFIG, STATIC_PATHS } from './server/initializers/constants'
 checkFFmpeg(CONFIG)
+  .catch(err => {
+    logger.error('Error in ffmpeg check.', { err })
+    process.exit(-1)
+  })
 
 const errorMessage = checkConfig()
 if (errorMessage !== null) {
@@ -41,8 +49,6 @@ if (errorMessage !== null) {
 }
 
 // ----------- Database -----------
-// Do not use barrels because we don't want to load all modules here (we need to initialize database first)
-import { logger } from './server/helpers/logger'
 
 // Initialize database and models
 import { initDatabaseModels } from './server/initializers/database'
index 4a0a44cd395f7959e0ec8433f5dffa8c107034b4..bb0063473a9502c8ced3e0ed614beef36ce449b0 100644 (file)
@@ -93,14 +93,14 @@ async function followRetry (req: express.Request, res: express.Response, next: e
 
         return retryTransactionWrapper(follow, options)
       })
-      .catch(err => logger.warn('Cannot follow server %s.', sanitizedHost, err))
+      .catch(err => logger.warn('Cannot follow server %s.', sanitizedHost, { err }))
 
     tasks.push(p)
   }
 
   // Don't make the client wait the tasks
   Promise.all(tasks)
-    .catch(err => logger.error('Error in follow.', err))
+    .catch(err => logger.error('Error in follow.', { err }))
 
   return res.status(204).end()
 }
@@ -144,7 +144,7 @@ async function removeFollow (req: express.Request, res: express.Response, next:
   // This could be long so don't wait this task
   const following = follow.ActorFollowing
   following.destroy()
-    .catch(err => logger.error('Cannot destroy actor that we do not follow anymore %s.', following.url, err))
+    .catch(err => logger.error('Cannot destroy actor that we do not follow anymore %s.', following.url, { err }))
 
   return res.status(204).end()
 }
index 7eee460d4f1e087488e9b7a334b32c42884b40ed..8112b59b804464e6eb0fc3653e81d8d6f5876fcc 100644 (file)
@@ -69,7 +69,7 @@ async function removeVideoFromBlacklistController (req: express.Request, res: ex
 
     return res.sendStatus(204)
   } catch (err) {
-    logger.error('Some error while removing video %s from blacklist.', res.locals.video.uuid, err)
+    logger.error('Some error while removing video %s from blacklist.', res.locals.video.uuid, { err })
     throw err
   }
 }
index fba5681de79689b143d2c8a01efe770a185caaaa..e547d375f0eedf193232bcc2b33132d30fcd69d5 100644 (file)
@@ -98,7 +98,7 @@ async function addVideoChannel (req: express.Request, res: express.Response) {
   })
 
   setAsyncActorKeys(videoChannelCreated.Actor)
-    .catch(err => logger.error('Cannot set async actor keys for account %s.', videoChannelCreated.Actor.uuid, err))
+    .catch(err => logger.error('Cannot set async actor keys for account %s.', videoChannelCreated.Actor.uuid, { err }))
 
   logger.info('Video channel with uuid %s created.', videoChannelCreated.Actor.uuid)
 
@@ -137,7 +137,7 @@ async function updateVideoChannel (req: express.Request, res: express.Response)
 
     logger.info('Video channel with name %s and uuid %s updated.', videoChannelInstance.name, videoChannelInstance.Actor.uuid)
   } catch (err) {
-    logger.debug('Cannot update the video channel.', err)
+    logger.debug('Cannot update the video channel.', { err })
 
     // Force fields we want to update
     // If the transaction is retried, sequelize will think the object has not changed
index d09b4b245b60bb81ab3181933d8a52363e76335a..47a0abfd206a9462ba019afa4cd5fb2339b88d9a 100644 (file)
@@ -16,7 +16,7 @@ function retryTransactionWrapper <T> (
         .catch(err => callback(err))
   })
   .catch(err => {
-    logger.error(options.errorMessage, err)
+    logger.error(options.errorMessage, { err })
     throw err
   })
 }
index 8f9a03c263d0569dbf85651d7ea501cda39d04f0..bfc942fa3c82440cf9ed41b311b945498c57d055 100644 (file)
@@ -64,12 +64,12 @@ async function generateImageFromVideoFile (fromPath: string, folder: string, ima
     const destination = join(folder, imageName)
     await processImage({ path: pendingImagePath }, destination, size)
   } catch (err) {
-    logger.error('Cannot generate image from video %s.', fromPath, err)
+    logger.error('Cannot generate image from video %s.', fromPath, { err })
 
     try {
       await unlinkPromise(pendingImagePath)
     } catch (err) {
-      logger.debug('Cannot remove pending image path after generation error.', err)
+      logger.debug('Cannot remove pending image path after generation error.', { err })
     }
   }
 }
index 7968b5ec9904f30e35f53f511e1ac38234132d8e..d92381a2c72e1ed715dbe6230742ad0c402117d7 100644 (file)
@@ -18,7 +18,11 @@ const excludedKeys = {
   label: true
 }
 function keysExcluder (key, value) {
-  return excludedKeys[key] === true ? undefined : value
+  if (excludedKeys[key] === true) return undefined
+
+  if (key === 'err') return value.stack
+
+  return value
 }
 
 const consoleLoggerFormat = winston.format.printf(info => {
@@ -30,8 +34,14 @@ const consoleLoggerFormat = winston.format.printf(info => {
   return `[${info.label}] ${info.timestamp} ${info.level}: ${info.message}${additionalInfos}`
 })
 
-const jsonLoggerFormat = winston.format.printf(info => {
-  if (info.message && info.message.stack !== undefined) info.message = info.message.stack
+const jsonLoggerFormat = winston.format.printf(infoArg => {
+  let info = infoArg.err
+    ? Object.assign({}, infoArg, { err: infoArg.err.stack })
+    : infoArg
+
+  if (infoArg.message && infoArg.message.stack !== undefined) {
+    info = Object.assign({}, info, { message: infoArg.message.stack })
+  }
 
   return JSON.stringify(info)
 })
index 313c12e26fe07f78b1bca2db159602037fdcb05d..5c182961d4a8a41e1413ea1d33bc99df1a191178 100644 (file)
@@ -35,7 +35,7 @@ function isSignatureVerified (fromActor: ActorModel, signedDocument: object) {
 
   return jsig.promises.verify(signedDocument, options)
     .catch(err => {
-      logger.error('Cannot check signature.', err)
+      logger.error('Cannot check signature.', { err })
       return false
     })
 }
index 3b618360bc25c52b37a86734c7a00d430e9cf958..c581172195072fb52d7437f32ddcf6ceba869bc3 100644 (file)
@@ -44,7 +44,7 @@ function createReqFiles (
       try {
         randomString = await generateRandomString(16)
       } catch (err) {
-        logger.error('Cannot generate random string for file name.', err)
+        logger.error('Cannot generate random string for file name.', { err })
         randomString = 'fake-random-string'
       }
 
index 324a2c2e5bdd4eefa0fca36f6627c2804db696bf..d2f6c7c8c4f8ecbe6e506c66b941e414b5540e1b 100644 (file)
@@ -19,7 +19,7 @@ async function installApplication () {
     await createOAuthClientIfNotExist()
     await createOAuthAdminIfNotExist()
   } catch (err) {
-    logger.error('Cannot install application.', err)
+    logger.error('Cannot install application.', { err })
     process.exit(-1)
   }
 }
index c767acc831cd174e0bbaa6bf30c6d5a337c4da49..4663697299ff830f2825e7e5096f53f42d051deb 100644 (file)
@@ -35,7 +35,7 @@ async function migrate () {
     try {
       await executeMigration(actualVersion, migrationScript)
     } catch (err) {
-      logger.error('Cannot execute migration %s.', migrationScript.version, err)
+      logger.error('Cannot execute migration %s.', migrationScript.version, { err })
       process.exit(-1)
     }
   }
index fa31e71c76aaf15ce1070b8f96290450dfd3cd2b..b0cf9bb17b0c31652afad0b150add4e52f6474b1 100644 (file)
@@ -30,7 +30,7 @@ function setAsyncActorKeys (actor: ActorModel) {
       return actor.save()
     })
     .catch(err => {
-      logger.error('Cannot set public/private keys of actor %d.', actor.uuid, err)
+      logger.error('Cannot set public/private keys of actor %d.', actor.uuid, { err })
       return actor
     })
 }
@@ -117,7 +117,7 @@ async function updateActorAvatarInstance (actorInstance: ActorModel, avatarName:
       try {
         await actorInstance.Avatar.destroy({ transaction: t })
       } catch (err) {
-        logger.error('Cannot remove old avatar of actor %s.', actorInstance.url, err)
+        logger.error('Cannot remove old avatar of actor %s.', actorInstance.url, { err })
       }
     }
 
@@ -144,7 +144,7 @@ async function fetchActorTotalItems (url: string) {
     const { body } = await doRequest(options)
     return body.totalItems ? body.totalItems : 0
   } catch (err) {
-    logger.warn('Cannot fetch remote actor count %s.', url, err)
+    logger.warn('Cannot fetch remote actor count %s.', url, { err })
     return 0
   }
 }
@@ -393,7 +393,7 @@ async function refreshActorIfNeeded (actor: ActorModel) {
       return actor
     })
   } catch (err) {
-    logger.warn('Cannot refresh actor.', err)
+    logger.warn('Cannot refresh actor.', { err })
     return actor
   }
 }
index 24e5589d4a63de8280a5b7c867550438ef978b94..51e3cc4e3b7127d22efa0b4b1cf3718ffff4699d 100644 (file)
@@ -92,7 +92,7 @@ async function updateRemoteVideo (actor: ActorModel, activity: ActivityUpdate) {
 
       // Don't block on request
       generateThumbnailFromUrl(videoInstance, videoAttributesToUpdate.icon)
-        .catch(err => logger.warn('Cannot generate thumbnail of %s.', videoAttributesToUpdate.id, err))
+        .catch(err => logger.warn('Cannot generate thumbnail of %s.', videoAttributesToUpdate.id, { err }))
 
       // Remove old video files
       const videoFileDestroyTasks: Bluebird<void>[] = []
@@ -117,7 +117,7 @@ async function updateRemoteVideo (actor: ActorModel, activity: ActivityUpdate) {
     }
 
     // This is just a debug because we will retry the insert
-    logger.debug('Cannot update the remote video.', err)
+    logger.debug('Cannot update the remote video.', { err })
     throw err
   }
 }
@@ -176,7 +176,7 @@ async function updateRemoteActor (actor: ActorModel, activity: ActivityUpdate) {
     }
 
     // This is just a debug because we will retry the insert
-    logger.debug('Cannot update the remote account.', err)
+    logger.debug('Cannot update the remote account.', { err })
     throw err
   }
 }
index b33ae27b19ddcc7a4d51b2bcd5a6c45543d5671d..8ab0cdba4211de4615350eb76e9d0ba11ffe2fc4 100644 (file)
@@ -111,7 +111,7 @@ async function resolveThread (url: string, comments: VideoCommentModel[] = []) {
 
     return { video, parents: comments }
   } catch (err) {
-    logger.debug('Cannot get or create account and video and channel for reply %s, fetch comment', url, err)
+    logger.debug('Cannot get or create account and video and channel for reply %s, fetch comment', url, { err })
 
     if (comments.length > ACTIVITY_PUB.MAX_RECURSION_COMMENTS) {
       throw new Error('Recursion limit reached when resolving a thread')
index 2a66366256e0cf9da1f13ca869f66f21e898f567..ffba1570b07ee35a8318a11ac7207fb22ddfef86 100644 (file)
@@ -152,7 +152,7 @@ async function getOrCreateVideo (videoObject: VideoTorrentObject, channelActor:
 
     // Don't block on request
     generateThumbnailFromUrl(video, videoObject.icon)
-      .catch(err => logger.warn('Cannot generate thumbnail of %s.', videoObject.id, err))
+      .catch(err => logger.warn('Cannot generate thumbnail of %s.', videoObject.id, { err }))
 
     const videoCreated = await video.save(sequelizeOptions)
 
index f34d141ea92bcae376eef23efa641ab100ad5241..85cc725fa9991b2e58c54a98362f91f65ffa5f7c 100644 (file)
@@ -119,7 +119,7 @@ class Emailer {
   }
 
   private dieOnConnectionFailure (err?: Error) {
-    logger.error('Failed to connect to SMTP %s:%d.', CONFIG.SMTP.HOSTNAME, CONFIG.SMTP.PORT, err)
+    logger.error('Failed to connect to SMTP %s:%d.', CONFIG.SMTP.HOSTNAME, CONFIG.SMTP.PORT, { err })
     process.exit(-1)
   }
 
index 66cced59a6e76b0928926a8ed0fd35e356aebcc3..1dc28755e5d90c10ccdec6416066311c99347175 100644 (file)
@@ -53,7 +53,7 @@ class JobQueue {
     this.jobQueue.setMaxListeners(15)
 
     this.jobQueue.on('error', err => {
-      logger.error('Error in job queue.', err)
+      logger.error('Error in job queue.', { err })
       process.exit(-1)
     })
     this.jobQueue.watchStuckJobs(5000)
@@ -111,7 +111,7 @@ class JobQueue {
     const now = new Date().getTime()
     kue.Job.rangeByState('complete', 0, -1, 'asc', (err, jobs) => {
       if (err) {
-        logger.error('Cannot get jobs when removing old jobs.', err)
+        logger.error('Cannot get jobs when removing old jobs.', { err })
         return
       }
 
index 1fd366401c31445d455e6027983c90e2c5542e01..41f4c986989c0d5754ad5f48abfbd23122008c74 100644 (file)
@@ -23,7 +23,7 @@ class Redis {
     })
 
     this.client.on('error', err => {
-      logger.error('Error in Redis client.', err)
+      logger.error('Error in Redis client.', { err })
       process.exit(-1)
     })
 
index 9b9f9e17ddf9a2e5ca40c3a754cdecc41d5a49dc..121f7145e3b657d0698848e4c93bbadc76a20bc6 100644 (file)
@@ -17,7 +17,7 @@ export class BadActorFollowScheduler extends AbstractScheduler {
     try {
       await ActorFollowModel.removeBadActorFollows()
     } catch (err) {
-      logger.error('Error in bad actor follows scheduler.', err)
+      logger.error('Error in bad actor follows scheduler.', { err })
     }
   }
 
index 1488b42ab1164bd701db841182da7d92c7eb0613..12d5c22c54acb15965538cd99bb9573d27e632d5 100644 (file)
@@ -18,7 +18,7 @@ async function checkSignature (req: Request, res: Response, next: NextFunction)
   try {
     actor = await getOrCreateActorAndServerAndModel(creator)
   } catch (err) {
-    logger.error('Cannot create remote actor and check signature.', err)
+    logger.error('Cannot create remote actor and check signature.', { err })
     return res.sendStatus(403)
   }
 
index 1dc8429c8b38c6fa0b4dbfcb5127d47e5b0acf04..e3543ef9338c96c37f33592b0779352c9041a85e 100644 (file)
@@ -86,7 +86,7 @@ const videosAddValidator = [
     try {
       duration = await getDurationFromVideoFile(videoFile.path)
     } catch (err) {
-      logger.error('Invalid input file in videosAddValidator.', err)
+      logger.error('Invalid input file in videosAddValidator.', { err })
       res.status(400)
          .json({ error: 'Invalid input file.' })
          .end()
index d3c438626ad35a58463ad7f64443c6be44780654..c97f4cead2a773442bd5805fc7e8445bbf35ebb7 100644 (file)
@@ -118,12 +118,12 @@ export class ActorFollowModel extends Model<ActorFollowModel> {
 
     if (goodInboxes.length !== 0) {
       ActorFollowModel.incrementScores(goodInboxes, ACTOR_FOLLOW_SCORE.BONUS, t)
-        .catch(err => logger.error('Cannot increment scores of good actor follows.', err))
+        .catch(err => logger.error('Cannot increment scores of good actor follows.', { err }))
     }
 
     if (badInboxes.length !== 0) {
       ActorFollowModel.incrementScores(badInboxes, ACTOR_FOLLOW_SCORE.PENALTY, t)
-        .catch(err => logger.error('Cannot decrement scores of bad actor follows.', err))
+        .catch(err => logger.error('Cannot decrement scores of bad actor follows.', { err }))
     }
   }
 
index 528bb9587d7ba648ec1c9885446b16065ece8886..759aa27797aa16efb555a1d7b7fa85c1299dbf55 100644 (file)
@@ -125,7 +125,7 @@ export class OAuthTokenModel extends Model<OAuthTokenModel> {
         } as OAuthTokenInfo
       })
       .catch(err => {
-        logger.info('getRefreshToken error.', err)
+        logger.info('getRefreshToken error.', { err })
         throw err
       })
   }
index f43b73e49c7d978151c87a645ef8cfa36dd3f366..13bf0b6a2f574b3233eafe63e2be06e26c6fca07 100644 (file)
@@ -473,7 +473,7 @@ export class VideoModel extends Model<VideoModel> {
 
     return Promise.all(tasks)
       .catch(err => {
-        logger.error('Some errors when removing files of video %s in after destroy hook.', instance.uuid, err)
+        logger.error('Some errors when removing files of video %s in after destroy hook.', instance.uuid, { err })
       })
   }
 
@@ -1213,7 +1213,7 @@ export class VideoModel extends Model<VideoModel> {
 
     } catch (err) {
       // Auto destruction...
-      this.destroy().catch(err => logger.error('Cannot destruct video after transcoding failure.', err))
+      this.destroy().catch(err => logger.error('Cannot destruct video after transcoding failure.', { err }))
 
       throw err
     }