Fix error logging

24 files changed, 57 insertions, 41 deletions

diff --git a/server.ts b/server.ts
index 56a4a0c44..f6794b897 100644
--- 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'
diff --git a/server/controllers/api/server/follows.ts b/server/controllers/api/server/follows.ts
index 4a0a44cd3..bb0063473 100644
--- a/server/controllers/api/server/follows.ts
+++ b/server/controllers/api/server/follows.ts
@@ -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()
 }
diff --git a/server/controllers/api/videos/blacklist.ts b/server/controllers/api/videos/blacklist.ts
index 7eee460d4..8112b59b8 100644
--- a/server/controllers/api/videos/blacklist.ts
+++ b/server/controllers/api/videos/blacklist.ts
@@ -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
   }
 }
diff --git a/server/controllers/api/videos/channel.ts b/server/controllers/api/videos/channel.ts
index fba5681de..e547d375f 100644
--- a/server/controllers/api/videos/channel.ts
+++ b/server/controllers/api/videos/channel.ts
@@ -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
diff --git a/server/helpers/database-utils.ts b/server/helpers/database-utils.ts
index d09b4b245..47a0abfd2 100644
--- a/server/helpers/database-utils.ts
+++ b/server/helpers/database-utils.ts
@@ -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
   })
 }
diff --git a/server/helpers/ffmpeg-utils.ts b/server/helpers/ffmpeg-utils.ts
index 8f9a03c26..bfc942fa3 100644
--- a/server/helpers/ffmpeg-utils.ts
+++ b/server/helpers/ffmpeg-utils.ts
@@ -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 })
     }
   }
 }
diff --git a/server/helpers/logger.ts b/server/helpers/logger.ts
index 7968b5ec9..d92381a2c 100644
--- a/server/helpers/logger.ts
+++ b/server/helpers/logger.ts
@@ -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)
 })
diff --git a/server/helpers/peertube-crypto.ts b/server/helpers/peertube-crypto.ts
index 313c12e26..5c182961d 100644
--- a/server/helpers/peertube-crypto.ts
+++ b/server/helpers/peertube-crypto.ts
@@ -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
     })
 }
diff --git a/server/helpers/utils.ts b/server/helpers/utils.ts
index 3b618360b..c58117219 100644
--- a/server/helpers/utils.ts
+++ b/server/helpers/utils.ts
@@ -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'
       }
 
diff --git a/server/initializers/installer.ts b/server/initializers/installer.ts
index 324a2c2e5..d2f6c7c8c 100644
--- a/server/initializers/installer.ts
+++ b/server/initializers/installer.ts
@@ -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)
   }
 }
diff --git a/server/initializers/migrator.ts b/server/initializers/migrator.ts
index c767acc83..466369729 100644
--- a/server/initializers/migrator.ts
+++ b/server/initializers/migrator.ts
@@ -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)
     }
   }
diff --git a/server/lib/activitypub/actor.ts b/server/lib/activitypub/actor.ts
index fa31e71c7..b0cf9bb17 100644
--- a/server/lib/activitypub/actor.ts
+++ b/server/lib/activitypub/actor.ts
@@ -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
   }
 }
diff --git a/server/lib/activitypub/process/process-update.ts b/server/lib/activitypub/process/process-update.ts
index 24e5589d4..51e3cc4e3 100644
--- a/server/lib/activitypub/process/process-update.ts
+++ b/server/lib/activitypub/process/process-update.ts
@@ -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
   }
 }
diff --git a/server/lib/activitypub/video-comments.ts b/server/lib/activitypub/video-comments.ts
index b33ae27b1..8ab0cdba4 100644
--- a/server/lib/activitypub/video-comments.ts
+++ b/server/lib/activitypub/video-comments.ts
@@ -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')
diff --git a/server/lib/activitypub/videos.ts b/server/lib/activitypub/videos.ts
index 2a6636625..ffba1570b 100644
--- a/server/lib/activitypub/videos.ts
+++ b/server/lib/activitypub/videos.ts
@@ -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)
 
diff --git a/server/lib/emailer.ts b/server/lib/emailer.ts
index f34d141ea..85cc725fa 100644
--- a/server/lib/emailer.ts
+++ b/server/lib/emailer.ts
@@ -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)
   }
 
diff --git a/server/lib/job-queue/job-queue.ts b/server/lib/job-queue/job-queue.ts
index 66cced59a..1dc28755e 100644
--- a/server/lib/job-queue/job-queue.ts
+++ b/server/lib/job-queue/job-queue.ts
@@ -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
       }
 
diff --git a/server/lib/redis.ts b/server/lib/redis.ts
index 1fd366401..41f4c9869 100644
--- a/server/lib/redis.ts
+++ b/server/lib/redis.ts
@@ -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)
     })
 
diff --git a/server/lib/schedulers/bad-actor-follow-scheduler.ts b/server/lib/schedulers/bad-actor-follow-scheduler.ts
index 9b9f9e17d..121f7145e 100644
--- a/server/lib/schedulers/bad-actor-follow-scheduler.ts
+++ b/server/lib/schedulers/bad-actor-follow-scheduler.ts
@@ -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 })
     }
   }
 
diff --git a/server/middlewares/activitypub.ts b/server/middlewares/activitypub.ts
index 1488b42ab..12d5c22c5 100644
--- a/server/middlewares/activitypub.ts
+++ b/server/middlewares/activitypub.ts
@@ -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)
   }
 
diff --git a/server/middlewares/validators/videos.ts b/server/middlewares/validators/videos.ts
index 1dc8429c8..e3543ef93 100644
--- a/server/middlewares/validators/videos.ts
+++ b/server/middlewares/validators/videos.ts
@@ -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()
diff --git a/server/models/activitypub/actor-follow.ts b/server/models/activitypub/actor-follow.ts
index d3c438626..c97f4cead 100644
--- a/server/models/activitypub/actor-follow.ts
+++ b/server/models/activitypub/actor-follow.ts
@@ -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 }))
     }
   }
 
diff --git a/server/models/oauth/oauth-token.ts b/server/models/oauth/oauth-token.ts
index 528bb9587..759aa2779 100644
--- a/server/models/oauth/oauth-token.ts
+++ b/server/models/oauth/oauth-token.ts
@@ -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
       })
   }
diff --git a/server/models/video/video.ts b/server/models/video/video.ts
index f43b73e49..13bf0b6a2 100644
--- a/server/models/video/video.ts
+++ b/server/models/video/video.ts
@@ -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
     }