From 452b3bea082481b84537e55c7cedc1e24860d543 Mon Sep 17 00:00:00 2001 From: Chocobozzz Date: Fri, 5 Mar 2021 13:26:02 +0100 Subject: Introduce tags to the logger That could help to filter unneeded logs and/or select particular components --- scripts/parse-log.ts | 23 +++++++++++++++++++++++ server.ts | 4 +++- server/controllers/api/videos/index.ts | 11 ++++++----- server/helpers/logger.ts | 10 +++++++++- server/initializers/database.ts | 2 +- server/lib/activitypub/send/send-create.ts | 10 ++++++---- server/lib/activitypub/share.ts | 23 ++++++++++++++--------- server/lib/video-blacklist.ts | 6 ++++-- 8 files changed, 66 insertions(+), 23 deletions(-) diff --git a/scripts/parse-log.ts b/scripts/parse-log.ts index 3679dab74..5f4480c88 100755 --- a/scripts/parse-log.ts +++ b/scripts/parse-log.ts @@ -15,6 +15,8 @@ import { format as sqlFormat } from 'sql-formatter' program .option('-l, --level [level]', 'Level log (debug/info/warn/error)') .option('-f, --files [file...]', 'Files to parse. If not provided, the script will parse the latest log file from config)') + .option('-t, --tags [tags...]', 'Display only lines with these tags') + .option('-nt, --not-tags [tags...]', 'Donrt display lines containing these tags') .parse(process.argv) const options = program.opts() @@ -24,6 +26,7 @@ const excludedKeys = { message: true, splat: true, timestamp: true, + tags: true, label: true, sql: true } @@ -93,6 +96,14 @@ function run () { rl.on('line', line => { try { const log = JSON.parse(line) + if (options.tags && !containsTags(log.tags, options.tags)) { + return + } + + if (options.notTags && containsTags(log.tags, options.notTags)) { + return + } + // Don't know why but loggerFormat does not remove splat key Object.assign(log, { splat: undefined }) @@ -131,3 +142,15 @@ function toTimeFormat (time: string) { return new Date(timestamp).toISOString() } + +function containsTags (loggerTags: string[], optionsTags: string[]) { + if (!loggerTags) return false + + for (const lt of loggerTags) { + for (const ot of optionsTags) { + if (lt === ot) return true + } + } + + return false +} diff --git a/server.ts b/server.ts index 00cd87e20..1cc29209e 100644 --- a/server.ts +++ b/server.ts @@ -160,7 +160,9 @@ morgan.token('user-agent', (req: express.Request) => { return req.get('user-agent') }) app.use(morgan('combined', { - stream: { write: logger.info.bind(logger) }, + stream: { + write: (str: string) => logger.info(str, { tags: [ 'http' ] }) + }, skip: req => CONFIG.LOG.LOG_PING_REQUESTS === false && req.originalUrl === '/api/v1/ping' })) diff --git a/server/controllers/api/videos/index.ts b/server/controllers/api/videos/index.ts index 2447c1288..7fee278f2 100644 --- a/server/controllers/api/videos/index.ts +++ b/server/controllers/api/videos/index.ts @@ -17,7 +17,7 @@ import { auditLoggerFactory, getAuditIdFromRes, VideoAuditView } from '../../../ import { resetSequelizeInstance, retryTransactionWrapper } from '../../../helpers/database-utils' import { buildNSFWFilter, createReqFiles, getCountVideos } from '../../../helpers/express-utils' import { getMetadataFromFile, getVideoFileFPS, getVideoFileResolution } from '../../../helpers/ffprobe-utils' -import { logger } from '../../../helpers/logger' +import { logger, loggerTagsFactory } from '../../../helpers/logger' import { getFormattedObjects } from '../../../helpers/utils' import { CONFIG } from '../../../initializers/config' import { @@ -67,6 +67,7 @@ import { ownershipVideoRouter } from './ownership' import { rateVideoRouter } from './rate' import { watchingRouter } from './watching' +const lTags = loggerTagsFactory('api', 'video') const auditLogger = auditLoggerFactory('videos') const videosRouter = express.Router() @@ -257,14 +258,14 @@ async function addVideo (req: express.Request, res: express.Response) { }) auditLogger.create(getAuditIdFromRes(res), new VideoAuditView(videoCreated.toFormattedDetailsJSON())) - logger.info('Video with name %s and uuid %s created.', videoInfo.name, videoCreated.uuid) + logger.info('Video with name %s and uuid %s created.', videoInfo.name, videoCreated.uuid, lTags(videoCreated.uuid)) return { videoCreated } }) // Create the torrent file in async way because it could be long createTorrentAndSetInfoHashAsync(video, videoFile) - .catch(err => logger.error('Cannot create torrent file for video %s', video.url, { err })) + .catch(err => logger.error('Cannot create torrent file for video %s', video.url, { err, ...lTags(video.uuid) })) .then(() => VideoModel.loadAndPopulateAccountAndServerAndTags(video.id)) .then(refreshedVideo => { if (!refreshedVideo) return @@ -276,7 +277,7 @@ async function addVideo (req: express.Request, res: express.Response) { return sequelizeTypescript.transaction(t => federateVideoIfNeeded(refreshedVideo, true, t)) }) }) - .catch(err => logger.error('Cannot federate or notify video creation %s', video.url, { err })) + .catch(err => logger.error('Cannot federate or notify video creation %s', video.url, { err, ...lTags(video.uuid) })) if (video.state === VideoState.TO_TRANSCODE) { await addOptimizeOrMergeAudioJob(videoCreated, videoFile, res.locals.oauth.token.User) @@ -389,7 +390,7 @@ async function updateVideo (req: express.Request, res: express.Response) { new VideoAuditView(videoInstanceUpdated.toFormattedDetailsJSON()), oldVideoAuditView ) - logger.info('Video with name %s and uuid %s updated.', videoInstance.name, videoInstance.uuid) + logger.info('Video with name %s and uuid %s updated.', videoInstance.name, videoInstance.uuid, lTags(videoInstance.uuid)) return videoInstanceUpdated }) diff --git a/server/helpers/logger.ts b/server/helpers/logger.ts index 6917a64d9..a112fd300 100644 --- a/server/helpers/logger.ts +++ b/server/helpers/logger.ts @@ -48,7 +48,7 @@ function getLoggerReplacer () { } const consoleLoggerFormat = winston.format.printf(info => { - const toOmit = [ 'label', 'timestamp', 'level', 'message', 'sql' ] + const toOmit = [ 'label', 'timestamp', 'level', 'message', 'sql', 'tags' ] const obj = omit(info, ...toOmit) @@ -150,6 +150,13 @@ const bunyanLogger = { error: bunyanLogFactory('error'), fatal: bunyanLogFactory('error') } + +function loggerTagsFactory (...defaultTags: string[]) { + return (...tags: string[]) => { + return { tags: defaultTags.concat(tags) } + } +} + // --------------------------------------------------------------------------- export { @@ -159,5 +166,6 @@ export { consoleLoggerFormat, jsonLoggerFormat, logger, + loggerTagsFactory, bunyanLogger } diff --git a/server/initializers/database.ts b/server/initializers/database.ts index 1f2b6d521..8378fa982 100644 --- a/server/initializers/database.ts +++ b/server/initializers/database.ts @@ -76,7 +76,7 @@ const sequelizeTypescript = new SequelizeTypescript({ newMessage += ' in ' + benchmark + 'ms' } - logger.debug(newMessage, { sql: message }) + logger.debug(newMessage, { sql: message, tags: [ 'sql' ] }) } }) diff --git a/server/lib/activitypub/send/send-create.ts b/server/lib/activitypub/send/send-create.ts index 9fb218224..baded642a 100644 --- a/server/lib/activitypub/send/send-create.ts +++ b/server/lib/activitypub/send/send-create.ts @@ -4,7 +4,7 @@ import { VideoPrivacy } from '../../../../shared/models/videos' import { VideoCommentModel } from '../../../models/video/video-comment' import { broadcastToActors, broadcastToFollowers, sendVideoRelatedActivity, unicastTo } from './utils' import { audiencify, getActorsInvolvedInVideo, getAudience, getAudienceFromFollowersOf, getVideoCommentAudience } from '../audience' -import { logger } from '../../../helpers/logger' +import { logger, loggerTagsFactory } from '../../../helpers/logger' import { VideoPlaylistPrivacy } from '../../../../shared/models/videos/playlist/video-playlist-privacy.model' import { MActorLight, @@ -18,10 +18,12 @@ import { import { getServerActor } from '@server/models/application/application' import { ContextType } from '@shared/models/activitypub/context' +const lTags = loggerTagsFactory('ap', 'create') + async function sendCreateVideo (video: MVideoAP, t: Transaction) { if (!video.hasPrivacyForFederation()) return undefined - logger.info('Creating job to send video creation of %s.', video.url) + logger.info('Creating job to send video creation of %s.', video.url, lTags(video.uuid)) const byActor = video.VideoChannel.Account.Actor const videoObject = video.toActivityPubObject() @@ -37,7 +39,7 @@ async function sendCreateCacheFile ( video: MVideoAccountLight, fileRedundancy: MVideoRedundancyStreamingPlaylistVideo | MVideoRedundancyFileVideo ) { - logger.info('Creating job to send file cache of %s.', fileRedundancy.url) + logger.info('Creating job to send file cache of %s.', fileRedundancy.url, lTags(video.uuid)) return sendVideoRelatedCreateActivity({ byActor, @@ -51,7 +53,7 @@ async function sendCreateCacheFile ( async function sendCreateVideoPlaylist (playlist: MVideoPlaylistFull, t: Transaction) { if (playlist.privacy === VideoPlaylistPrivacy.PRIVATE) return undefined - logger.info('Creating job to send create video playlist of %s.', playlist.url) + logger.info('Creating job to send create video playlist of %s.', playlist.url, lTags(playlist.uuid)) const byActor = playlist.OwnerAccount.Actor const audience = getAudience(byActor, playlist.privacy === VideoPlaylistPrivacy.PUBLIC) diff --git a/server/lib/activitypub/share.ts b/server/lib/activitypub/share.ts index 1f8a8f3c4..dde0c628e 100644 --- a/server/lib/activitypub/share.ts +++ b/server/lib/activitypub/share.ts @@ -1,15 +1,17 @@ -import { Transaction } from 'sequelize' -import { VideoShareModel } from '../../models/video/video-share' -import { sendUndoAnnounce, sendVideoAnnounce } from './send' -import { getLocalVideoAnnounceActivityPubUrl } from './url' import * as Bluebird from 'bluebird' +import { Transaction } from 'sequelize' +import { getServerActor } from '@server/models/application/application' +import { checkUrlsSameHost, getAPId } from '../../helpers/activitypub' +import { logger, loggerTagsFactory } from '../../helpers/logger' import { doRequest } from '../../helpers/requests' -import { getOrCreateActorAndServerAndModel } from './actor' -import { logger } from '../../helpers/logger' import { CRAWL_REQUEST_CONCURRENCY } from '../../initializers/constants' -import { checkUrlsSameHost, getAPId } from '../../helpers/activitypub' +import { VideoShareModel } from '../../models/video/video-share' import { MChannelActorLight, MVideo, MVideoAccountLight, MVideoId } from '../../types/models/video' -import { getServerActor } from '@server/models/application/application' +import { getOrCreateActorAndServerAndModel } from './actor' +import { sendUndoAnnounce, sendVideoAnnounce } from './send' +import { getLocalVideoAnnounceActivityPubUrl } from './url' + +const lTags = loggerTagsFactory('share') async function shareVideoByServerAndChannel (video: MVideoAccountLight, t: Transaction) { if (!video.hasPrivacyForFederation()) return undefined @@ -25,7 +27,10 @@ async function changeVideoChannelShare ( oldVideoChannel: MChannelActorLight, t: Transaction ) { - logger.info('Updating video channel of video %s: %s -> %s.', video.uuid, oldVideoChannel.name, video.VideoChannel.name) + logger.info( + 'Updating video channel of video %s: %s -> %s.', video.uuid, oldVideoChannel.name, video.VideoChannel.name, + lTags(video.uuid) + ) await undoShareByVideoChannel(video, oldVideoChannel, t) diff --git a/server/lib/video-blacklist.ts b/server/lib/video-blacklist.ts index dbb37e0b2..37c43c3b0 100644 --- a/server/lib/video-blacklist.ts +++ b/server/lib/video-blacklist.ts @@ -11,7 +11,7 @@ import { } from '@server/types/models' import { UserRight, VideoBlacklistCreate, VideoBlacklistType } from '../../shared/models' import { UserAdminFlag } from '../../shared/models/users/user-flag.model' -import { logger } from '../helpers/logger' +import { logger, loggerTagsFactory } from '../helpers/logger' import { CONFIG } from '../initializers/config' import { VideoBlacklistModel } from '../models/video/video-blacklist' import { sendDeleteVideo } from './activitypub/send' @@ -20,6 +20,8 @@ import { LiveManager } from './live-manager' import { Notifier } from './notifier' import { Hooks } from './plugins/hooks' +const lTags = loggerTagsFactory('blacklist') + async function autoBlacklistVideoIfNeeded (parameters: { video: MVideoWithBlacklistLight user?: MUser @@ -60,7 +62,7 @@ async function autoBlacklistVideoIfNeeded (parameters: { }) } - logger.info('Video %s auto-blacklisted.', video.uuid) + logger.info('Video %s auto-blacklisted.', video.uuid, lTags(video.uuid)) return true } -- cgit v1.2.3