From 463206948d6a9d46e7e68d55c7b763e601ecc870 Mon Sep 17 00:00:00 2001 From: Chocobozzz Date: Wed, 2 Jun 2021 16:49:59 +0200 Subject: [PATCH] Add tags to logs in AP videos --- server/helpers/logger.ts | 5 ++++- server/lib/activitypub/videos/refresh.ts | 10 +++++---- .../videos/shared/abstract-builder.ts | 5 +++-- .../lib/activitypub/videos/shared/creator.ts | 7 +++--- .../videos/shared/url-to-object.ts | 9 +++++--- .../videos/shared/video-sync-attributes.ts | 22 ++++++++++++------- server/lib/activitypub/videos/updater.ts | 13 +++++++---- 7 files changed, 46 insertions(+), 25 deletions(-) diff --git a/server/helpers/logger.ts b/server/helpers/logger.ts index a112fd300..29e06860d 100644 --- a/server/helpers/logger.ts +++ b/server/helpers/logger.ts @@ -151,7 +151,8 @@ const bunyanLogger = { fatal: bunyanLogFactory('error') } -function loggerTagsFactory (...defaultTags: string[]) { +type LoggerTagsFn = (...tags: string[]) => { tags: string[] } +function loggerTagsFactory (...defaultTags: string[]): LoggerTagsFn { return (...tags: string[]) => { return { tags: defaultTags.concat(tags) } } @@ -160,6 +161,8 @@ function loggerTagsFactory (...defaultTags: string[]) { // --------------------------------------------------------------------------- export { + LoggerTagsFn, + buildLogger, timestampFormatter, labelFormatter, diff --git a/server/lib/activitypub/videos/refresh.ts b/server/lib/activitypub/videos/refresh.ts index 205a3ccb1..da068cde9 100644 --- a/server/lib/activitypub/videos/refresh.ts +++ b/server/lib/activitypub/videos/refresh.ts @@ -1,4 +1,4 @@ -import { logger } from '@server/helpers/logger' +import { logger, loggerTagsFactory } from '@server/helpers/logger' import { PeerTubeRequestError } from '@server/helpers/requests' import { VideoFetchByUrlType } from '@server/helpers/video' import { ActorFollowScoreCache } from '@server/lib/files-cache' @@ -8,6 +8,8 @@ import { HttpStatusCode } from '@shared/core-utils' import { fetchRemoteVideo, SyncParam, syncVideoExternalAttributes } from './shared' import { APVideoUpdater } from './updater' +const lTags = loggerTagsFactory('ap', 'video', 'refresh') + async function refreshVideoIfNeeded (options: { video: MVideoThumbnail fetchedType: VideoFetchByUrlType @@ -24,7 +26,7 @@ async function refreshVideoIfNeeded (options: { const { videoObject } = await fetchRemoteVideo(video.url) if (videoObject === undefined) { - logger.warn('Cannot refresh remote video %s: invalid body.', video.url) + logger.warn('Cannot refresh remote video %s: invalid body.', video.url, lTags(video.uuid)) await video.setAsRefreshed() return video @@ -40,14 +42,14 @@ async function refreshVideoIfNeeded (options: { return video } catch (err) { if ((err as PeerTubeRequestError).statusCode === HttpStatusCode.NOT_FOUND_404) { - logger.info('Cannot refresh remote video %s: video does not exist anymore. Deleting it.', video.url) + logger.info('Cannot refresh remote video %s: video does not exist anymore. Deleting it.', video.url, lTags(video.uuid)) // Video does not exist anymore await video.destroy() return undefined } - logger.warn('Cannot refresh video %s.', options.video.url, { err }) + logger.warn('Cannot refresh video %s.', options.video.url, { err, ...lTags(video.uuid) }) ActorFollowScoreCache.Instance.addBadServerId(video.VideoChannel.Actor.serverId) diff --git a/server/lib/activitypub/videos/shared/abstract-builder.ts b/server/lib/activitypub/videos/shared/abstract-builder.ts index c7631cd45..953710f6c 100644 --- a/server/lib/activitypub/videos/shared/abstract-builder.ts +++ b/server/lib/activitypub/videos/shared/abstract-builder.ts @@ -1,7 +1,7 @@ import { Transaction } from 'sequelize/types' import { checkUrlsSameHost } from '@server/helpers/activitypub' import { deleteNonExistingModels } from '@server/helpers/database-utils' -import { logger } from '@server/helpers/logger' +import { logger, LoggerTagsFn } from '@server/helpers/logger' import { createPlaceholderThumbnail, createVideoMiniatureFromUrl } from '@server/lib/thumbnail' import { setVideoTags } from '@server/lib/video' import { VideoCaptionModel } from '@server/models/video/video-caption' @@ -24,6 +24,7 @@ import { getTrackerUrls, setVideoTrackers } from './trackers' export abstract class APVideoAbstractBuilder { protected abstract videoObject: VideoObject + protected abstract lTags: LoggerTagsFn protected async getOrCreateVideoChannelFromVideoObject () { const channel = this.videoObject.attributedTo.find(a => a.type === 'Group') @@ -42,7 +43,7 @@ export abstract class APVideoAbstractBuilder { video, type: ThumbnailType.MINIATURE }).catch(err => { - logger.warn('Cannot generate thumbnail of %s.', this.videoObject.id, { err }) + logger.warn('Cannot generate thumbnail of %s.', this.videoObject.id, { err, ...this.lTags(video.uuid) }) return undefined }) diff --git a/server/lib/activitypub/videos/shared/creator.ts b/server/lib/activitypub/videos/shared/creator.ts index dd9bfb508..ba3f6f77f 100644 --- a/server/lib/activitypub/videos/shared/creator.ts +++ b/server/lib/activitypub/videos/shared/creator.ts @@ -1,5 +1,5 @@ -import { logger } from '@server/helpers/logger' +import { logger, loggerTagsFactory } from '@server/helpers/logger' import { sequelizeTypescript } from '@server/initializers/database' import { autoBlacklistVideoIfNeeded } from '@server/lib/video-blacklist' import { VideoModel } from '@server/models/video/video' @@ -9,13 +9,14 @@ import { APVideoAbstractBuilder } from './abstract-builder' import { getVideoAttributesFromObject } from './object-to-model-attributes' export class APVideoCreator extends APVideoAbstractBuilder { + protected lTags = loggerTagsFactory('ap', 'video', 'create') constructor (protected readonly videoObject: VideoObject) { super() } async create (waitThumbnail = false) { - logger.debug('Adding remote video %s.', this.videoObject.id) + logger.debug('Adding remote video %s.', this.videoObject.id, this.lTags(this.videoObject.uuid)) const channelActor = await this.getOrCreateVideoChannelFromVideoObject() const channel = channelActor.VideoChannel @@ -56,7 +57,7 @@ export class APVideoCreator extends APVideoAbstractBuilder { transaction: t }) - logger.info('Remote video with uuid %s inserted.', this.videoObject.uuid) + logger.info('Remote video with uuid %s inserted.', this.videoObject.uuid, this.lTags(videoCreated.uuid)) return { autoBlacklisted, videoCreated } } catch (err) { diff --git a/server/lib/activitypub/videos/shared/url-to-object.ts b/server/lib/activitypub/videos/shared/url-to-object.ts index b1ecac8ca..dba3e9480 100644 --- a/server/lib/activitypub/videos/shared/url-to-object.ts +++ b/server/lib/activitypub/videos/shared/url-to-object.ts @@ -1,16 +1,19 @@ import { checkUrlsSameHost } from '@server/helpers/activitypub' import { sanitizeAndCheckVideoTorrentObject } from '@server/helpers/custom-validators/activitypub/videos' -import { logger } from '@server/helpers/logger' +import { logger, loggerTagsFactory } from '@server/helpers/logger' import { doJSONRequest } from '@server/helpers/requests' import { VideoObject } from '@shared/models' +const lTags = loggerTagsFactory('ap', 'video') + async function fetchRemoteVideo (videoUrl: string): Promise<{ statusCode: number, videoObject: VideoObject }> { - logger.info('Fetching remote video %s.', videoUrl) + logger.info('Fetching remote video %s.', videoUrl, lTags(videoUrl)) const { statusCode, body } = await doJSONRequest(videoUrl, { activityPub: true }) if (sanitizeAndCheckVideoTorrentObject(body) === false || checkUrlsSameHost(body.id, videoUrl) !== true) { - logger.debug('Remote video JSON is not valid.', { body }) + logger.debug('Remote video JSON is not valid.', { body, ...lTags(videoUrl) }) + return { statusCode, videoObject: undefined } } diff --git a/server/lib/activitypub/videos/shared/video-sync-attributes.ts b/server/lib/activitypub/videos/shared/video-sync-attributes.ts index c1318abf7..102d40621 100644 --- a/server/lib/activitypub/videos/shared/video-sync-attributes.ts +++ b/server/lib/activitypub/videos/shared/video-sync-attributes.ts @@ -1,4 +1,4 @@ -import { logger } from '@server/helpers/logger' +import { logger, loggerTagsFactory } from '@server/helpers/logger' import { JobQueue } from '@server/lib/job-queue' import { AccountVideoRateModel } from '@server/models/account/account-video-rate' import { VideoCommentModel } from '@server/models/video/video-comment' @@ -10,6 +10,8 @@ import { addVideoShares } from '../../share' import { addVideoComments } from '../../video-comments' import { createRates } from '../../video-rates' +const lTags = loggerTagsFactory('ap', 'video') + type SyncParam = { likes: boolean dislikes: boolean @@ -60,29 +62,33 @@ function syncRates (type: 'like' | 'dislike', video: MVideo, fetchedVideo: Video const cleaner = crawlStartDate => AccountVideoRateModel.cleanOldRatesOf(video.id, type, crawlStartDate) return crawlCollectionPage(uri, handler, cleaner) - .catch(err => logger.error('Cannot add rate of video %s.', video.uuid, { err, rootUrl: uri })) + .catch(err => logger.error('Cannot add rate of video %s.', video.uuid, { err, rootUrl: uri, ...lTags(video.uuid) })) } function syncShares (video: MVideo, fetchedVideo: VideoObject, isSync: boolean) { + const uri = fetchedVideo.shares + if (!isSync) { - return createJob({ uri: fetchedVideo.shares, videoId: video.id, type: 'video-shares' }) + return createJob({ uri, videoId: video.id, type: 'video-shares' }) } const handler = items => addVideoShares(items, video) const cleaner = crawlStartDate => VideoShareModel.cleanOldSharesOf(video.id, crawlStartDate) - return crawlCollectionPage(fetchedVideo.shares, handler, cleaner) - .catch(err => logger.error('Cannot add shares of video %s.', video.uuid, { err, rootUrl: fetchedVideo.shares })) + return crawlCollectionPage(uri, handler, cleaner) + .catch(err => logger.error('Cannot add shares of video %s.', video.uuid, { err, rootUrl: uri, ...lTags(video.uuid) })) } function syncComments (video: MVideo, fetchedVideo: VideoObject, isSync: boolean) { + const uri = fetchedVideo.comments + if (!isSync) { - return createJob({ uri: fetchedVideo.comments, videoId: video.id, type: 'video-comments' }) + return createJob({ uri, videoId: video.id, type: 'video-comments' }) } const handler = items => addVideoComments(items) const cleaner = crawlStartDate => VideoCommentModel.cleanOldCommentsOf(video.id, crawlStartDate) - return crawlCollectionPage(fetchedVideo.comments, handler, cleaner) - .catch(err => logger.error('Cannot add comments of video %s.', video.uuid, { err, rootUrl: fetchedVideo.comments })) + return crawlCollectionPage(uri, handler, cleaner) + .catch(err => logger.error('Cannot add comments of video %s.', video.uuid, { err, rootUrl: uri, ...lTags(video.uuid) })) } diff --git a/server/lib/activitypub/videos/updater.ts b/server/lib/activitypub/videos/updater.ts index 11c177a68..9e1c74969 100644 --- a/server/lib/activitypub/videos/updater.ts +++ b/server/lib/activitypub/videos/updater.ts @@ -1,6 +1,6 @@ import { Transaction } from 'sequelize/types' import { resetSequelizeInstance } from '@server/helpers/database-utils' -import { logger } from '@server/helpers/logger' +import { logger, loggerTagsFactory } from '@server/helpers/logger' import { sequelizeTypescript } from '@server/initializers/database' import { Notifier } from '@server/lib/notifier' import { PeerTubeSocket } from '@server/lib/peertube-socket' @@ -19,6 +19,8 @@ export class APVideoUpdater extends APVideoAbstractBuilder { private readonly oldVideoChannel: MChannelAccountLight + protected lTags = loggerTagsFactory('ap', 'video', 'update') + constructor ( protected readonly videoObject: VideoObject, private readonly video: MVideoAccountLightBlacklistAllFiles @@ -34,7 +36,10 @@ export class APVideoUpdater extends APVideoAbstractBuilder { } async update (overrideTo?: string[]) { - logger.debug('Updating remote video "%s".', this.videoObject.uuid, { videoObject: this.videoObject }) + logger.debug( + 'Updating remote video "%s".', this.videoObject.uuid, + { videoObject: this.videoObject, ...this.lTags(this.videoObject.uuid) } + ) try { const channelActor = await this.getOrCreateVideoChannelFromVideoObject() @@ -77,7 +82,7 @@ export class APVideoUpdater extends APVideoAbstractBuilder { PeerTubeSocket.Instance.sendVideoViewsUpdate(videoUpdated) } - logger.info('Remote video with uuid %s updated', this.videoObject.uuid) + logger.info('Remote video with uuid %s updated', this.videoObject.uuid, this.lTags(this.videoObject.uuid)) return videoUpdated } catch (err) { @@ -153,7 +158,7 @@ export class APVideoUpdater extends APVideoAbstractBuilder { } // 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, ...this.lTags(this.videoObject.uuid) }) throw err } }