From fc3da71ff9c149db507756b00d7cbfb70bd548fb Mon Sep 17 00:00:00 2001 From: Marco Link Date: Mon, 17 Jul 2023 11:39:04 +0200 Subject: [PATCH] feat: add more logging to the task system [NONE] --- src/engine/client/index.ts | 25 +++++++------ ...te-affected-content-types-diverged-task.ts | 7 ++-- .../tasks/create-compute-ids-task.ts | 8 +++-- .../tasks/create-entities-task.ts | 35 +++++++++++++------ .../tasks/create-fetch-added-entities-task.ts | 19 ++++++---- .../tasks/create-fetch-changed-tasks.ts | 13 +++++-- src/engine/logger/create-scoped-logger.ts | 11 ++++++ 7 files changed, 82 insertions(+), 36 deletions(-) create mode 100644 src/engine/logger/create-scoped-logger.ts diff --git a/src/engine/client/index.ts b/src/engine/client/index.ts index 27e5c75eb..1d791131e 100644 --- a/src/engine/client/index.ts +++ b/src/engine/client/index.ts @@ -3,7 +3,7 @@ import { ContentTypeCollection, Entry, EntryCollection } from 'contentful' import { EntryProps } from 'contentful-management' import { createHttpClient, getUserAgentHeader } from 'contentful-sdk-core' import { pickBy } from 'lodash' -import { ClientLogHandler } from '../logger/types' +import { ClientLogHandler, ILogger, LogLevel } from '../logger/types' import { stripSys } from '../utils/strip-sys' import ContentfulSdkCorePKGJson from 'contentful-sdk-core/package.json' @@ -89,30 +89,30 @@ export const createClient = ({ cma: { requestCounts: () => count.cma, entries: { - getMany: async ({ environment, query }: GetEntriesParams) => { + getMany: async ({ environment, query }: GetEntriesParams, logger?: ILogger) => { count.cma++ const result = await cmaClient.get(`${environment}/entries`, { params: { ...cleanQuery(query) }, }) return result.data as EntryCollection }, - get: async ({ environment, entryId, query }: GetEntryParams) => { + get: async ({ environment, entryId, query }: GetEntryParams, logger?: ILogger) => { count.cma++ const result = await cmaClient.get(`${environment}/entries/${entryId}`, { params: { ...cleanQuery(query) }, }) return result.data as EntryProps }, - unpublish: async ({ environment, entryId }: DeleteEntryParams) => { + unpublish: async ({ environment, entryId }: DeleteEntryParams, logger?: ILogger) => { count.cma++ const result = await cmaClient.delete(`${environment}/entries/${entryId}/published`) return result.data as EntryProps }, - delete: async ({ environment, entryId }: DeleteEntryParams) => { + delete: async ({ environment, entryId }: DeleteEntryParams, logger?: ILogger) => { count.cma++ await cmaClient.delete(`${environment}/entries/${entryId}`) }, - create: async ({ environment, entry, entryId, contentType }: CreateEntryParams) => { + create: async ({ environment, entry, entryId, contentType }: CreateEntryParams, logger?: ILogger) => { count.cma++ const result = await cmaClient.put(`${environment}/entries/${entryId}`, stripSys(entry), { headers: { @@ -121,7 +121,7 @@ export const createClient = ({ }) return result.data as EntryProps }, - update: async ({ environment, entry, entryId }: UpdateEntryParams) => { + update: async ({ environment, entry, entryId }: UpdateEntryParams, logger?: ILogger) => { count.cma++ const result = await cmaClient.put(`${environment}/entries/${entryId}`, entry, { headers: { @@ -130,7 +130,7 @@ export const createClient = ({ }) return result.data as EntryProps }, - publish: async ({ environment, entry, entryId }: PublishEntryParams) => { + publish: async ({ environment, entry, entryId }: PublishEntryParams, logger?: ILogger) => { count.cma++ return cmaClient.put(`${environment}/entries/${entryId}/published`, entry, { headers: { @@ -143,15 +143,17 @@ export const createClient = ({ cda: { requestCounts: () => count.cda, entries: { - getMany: async ({ environment, query }: GetEntriesParams) => { + getMany: async ({ environment, query }: GetEntriesParams, logger?: ILogger) => { count.cda++ + logger?.log(LogLevel.INFO, `"GET /${space}/${`${environment}/entries`} ${JSON.stringify(query)}"`) const result = await cdaClient.get(`${environment}/entries`, { params: { ...cleanQuery(query) }, }) return result.data as EntryCollection }, - get: async ({ environment, entryId, query }: GetEntryParams) => { + get: async ({ environment, entryId, query }: GetEntryParams, logger?: ILogger) => { count.cda++ + logger?.log(LogLevel.INFO, `"GET /${space}/${environment}/entries/${entryId} ${JSON.stringify(query)}"`) const result = await cdaClient.get(`${environment}/entries/${entryId}`, { params: { ...cleanQuery(query) }, }) @@ -159,8 +161,9 @@ export const createClient = ({ }, }, contentTypes: { - getMany: async ({ environment, query }: GetEntriesParams) => { + getMany: async ({ environment, query }: GetEntriesParams, logger?: ILogger) => { count.cda++ + logger?.log(LogLevel.INFO, `"GET ${`/${space}/${environment}/content_types`} ${JSON.stringify(query)}"`) const result = await cdaClient.get(`${environment}/content_types`, { params: { ...cleanQuery(query) }, }) diff --git a/src/engine/create-changeset/tasks/create-affected-content-types-diverged-task.ts b/src/engine/create-changeset/tasks/create-affected-content-types-diverged-task.ts index 9a980001e..3d3069288 100644 --- a/src/engine/create-changeset/tasks/create-affected-content-types-diverged-task.ts +++ b/src/engine/create-changeset/tasks/create-affected-content-types-diverged-task.ts @@ -2,13 +2,14 @@ import { CreateChangesetContext } from '../types' import { ListrTask } from 'listr2' import { LogLevel } from '../../logger/types' import { affectedEntitiesIds } from '../../utils/affected-entities-ids' +import { createScopedLogger } from '../../logger/create-scoped-logger' export function createAffectedContentTypesDivergedTask(): ListrTask { return { title: `Checking for diverged content types`, task: async (context: CreateChangesetContext) => { - context.logger.log(LogLevel.INFO, `Start createAffectedContentTypesDivergedTask`) - + const logger = createScopedLogger(context.logger, `CreateAffectedContentTypesDivergedTask`) + logger.startScope() const affectedContentTypeIds = affectedEntitiesIds(context.affectedEntities.contentTypes, [ 'added', 'removed', @@ -29,7 +30,7 @@ export function createAffectedContentTypesDivergedTask(): ListrTask { if (contentModelDiverged.length) { context.contentModelDiverged = true } - + logger.stopScope() return context }, } diff --git a/src/engine/create-changeset/tasks/create-compute-ids-task.ts b/src/engine/create-changeset/tasks/create-compute-ids-task.ts index 257a6e752..32257fc84 100644 --- a/src/engine/create-changeset/tasks/create-compute-ids-task.ts +++ b/src/engine/create-changeset/tasks/create-compute-ids-task.ts @@ -3,6 +3,7 @@ import { LogLevel } from '../../logger/types' import { CreateChangesetContext, EnvironmentScope } from '../types' import { doesExceedLimits } from '../../utils/exceeds-limits' import { EntityType } from '../../types' +import { createScopedLogger } from '../../logger/create-scoped-logger' type ComputeIdsTaskProps = { entityType: EntityType } @@ -11,8 +12,9 @@ export const createComputeIdsTask = ({ entityType }: ComputeIdsTaskProps): Listr return { title: `Counting number of ${entityType} changes between environments`, task: async (context: CreateChangesetContext) => { - const { sourceData, targetData, logger } = context - logger.log(LogLevel.INFO, `Start computeIdsTask ${[entityType]}`) + const { sourceData, targetData } = context + const logger = createScopedLogger(context.logger, `CreateComputeIdsTask '${entityType}'`) + logger.startScope() const added = new Set(sourceData[entityType].ids.filter((item) => !targetData[entityType].ids.includes(item))) const removed = new Set(targetData[entityType].ids.filter((item) => !sourceData[entityType].ids.includes(item))) @@ -33,7 +35,7 @@ export const createComputeIdsTask = ({ entityType }: ComputeIdsTaskProps): Listr const exceedsLimits = doesExceedLimits(context, entityType) context.exceedsLimits = exceedsLimits - + logger.stopScope() return Promise.resolve(context) }, } diff --git a/src/engine/create-changeset/tasks/create-entities-task.ts b/src/engine/create-changeset/tasks/create-entities-task.ts index a579b0bf2..a942e836f 100644 --- a/src/engine/create-changeset/tasks/create-entities-task.ts +++ b/src/engine/create-changeset/tasks/create-entities-task.ts @@ -1,9 +1,10 @@ import type { ListrTaskWrapper } from 'listr2' import { ListrTask } from 'listr2' import pLimit from 'p-limit' -import { LogLevel } from '../../logger/types' +import { ILogger, LogLevel } from '../../logger/types' import { Comparable, CreateChangesetContext, EntityData, EnvironmentScope } from '../types' import { EntityType } from '../../types' +import { createScopedLogger } from '../../logger/create-scoped-logger' const LIMIT = 1000 @@ -14,9 +15,10 @@ type ExecuteParams = { environmentId: string entityType: EntityType additionalFields: string[] + logger: ILogger } -const execute = async ({ context, environmentId, task, entityType, additionalFields = [] }: ExecuteParams) => { +const execute = async ({ context, logger, environmentId, task, entityType, additionalFields = [] }: ExecuteParams) => { const { client: { cda }, } = context @@ -28,7 +30,7 @@ const execute = async ({ context, environmentId, task, entityType, additionalFie const api = cda[entityType] - const { total } = await api.getMany({ environment: environmentId, query: { limit: 0 } }) + const { total } = await api.getMany({ environment: environmentId, query: { limit: 0 } }, logger) const promises = [] let requestsDone = 0 @@ -40,10 +42,14 @@ const execute = async ({ context, environmentId, task, entityType, additionalFie for (let i = 0; i < iterations; i++) { promises.push( limiter(async () => { - const response = await api.getMany({ - environment: environmentId, - query: { select: ['sys.id', 'sys.updatedAt', ...additionalFields], limit: LIMIT, skip: LIMIT * i }, - }) + const query = { select: ['sys.id', 'sys.updatedAt', ...additionalFields], limit: LIMIT, skip: LIMIT * i } + const response = await api.getMany( + { + environment: environmentId, + query, + }, + logger + ) requestsDone++ task.output = `Fetching ${requestsDone * LIMIT}/${total} ${entityType}` result.push(...response.items) @@ -69,10 +75,19 @@ export function createEntitiesTask({ scope, environmentId, entityType }: Entitie return { title: `Reading the ${scope} environment "${environmentId}"`, task: async (context: CreateChangesetContext, task) => { - context.logger.log(LogLevel.INFO, `Start createEntitiesTask for ${entityType}`) + const logger = createScopedLogger(context.logger, `CreateEntitiesTask '${entityType}'`) + logger.startScope() const additionalFields = entityType === 'entries' ? ['sys.contentType.sys.id'] : [] - const result = await execute({ context, task, scope, environmentId, entityType, additionalFields }) - context[`${scope}Data`][entityType] = result + context[`${scope}Data`][entityType] = await execute({ + context, + task, + scope, + environmentId, + entityType, + additionalFields, + logger, + }) + logger.stopScope() return context }, } diff --git a/src/engine/create-changeset/tasks/create-fetch-added-entities-task.ts b/src/engine/create-changeset/tasks/create-fetch-added-entities-task.ts index 0040a85f7..04731082d 100644 --- a/src/engine/create-changeset/tasks/create-fetch-added-entities-task.ts +++ b/src/engine/create-changeset/tasks/create-fetch-added-entities-task.ts @@ -5,6 +5,7 @@ import { LogLevel } from '../../logger/types' import { CreateChangesetContext, SkipHandler } from '../types' import { pluralizeEntry } from '../../utils/pluralize' import { EntityType } from '../../types' +import { createScopedLogger } from '../../logger/create-scoped-logger' export function cleanEntity(entry: Entry): any { return { ...entry, sys: pick(entry.sys, ['id', 'type', 'contentType']) } @@ -20,8 +21,9 @@ export function createFetchAddedEntitiesTask({ entityType, skipHandler }: FetchA title: 'Fetching full payload for added entries', skip: skipHandler, task: async (context: CreateChangesetContext, task) => { - const { client, affectedEntities, sourceEnvironmentId, changeset, limit, logger } = context - logger.log(LogLevel.INFO, 'Start createFetchAddedEntitiesTask') + const { client, affectedEntities, sourceEnvironmentId, changeset, limit } = context + const logger = createScopedLogger(context.logger, `CreateFetchAddedEntitiesTask '${entityType}'`) + logger.startScope() const { [entityType]: { added }, @@ -38,10 +40,13 @@ export function createFetchAddedEntitiesTask({ entityType, skipHandler }: FetchA const query = { 'sys.id[in]': chunk.join(','), locale: '*', limit } // eslint-disable-next-line no-await-in-loop const entries = await client.cda.entries - .getMany({ - environment: sourceEnvironmentId, - query, - }) + .getMany( + { + environment: sourceEnvironmentId, + query, + }, + logger + ) .then((response) => response.items) for (const entry of entries) { @@ -51,6 +56,8 @@ export function createFetchAddedEntitiesTask({ entityType, skipHandler }: FetchA } } } + logger.startScope() + return context }, } } diff --git a/src/engine/create-changeset/tasks/create-fetch-changed-tasks.ts b/src/engine/create-changeset/tasks/create-fetch-changed-tasks.ts index c32af370e..83f2bce2a 100644 --- a/src/engine/create-changeset/tasks/create-fetch-changed-tasks.ts +++ b/src/engine/create-changeset/tasks/create-fetch-changed-tasks.ts @@ -6,6 +6,8 @@ import type { CreateChangesetContext } from '../types' import { createPatch } from '../../utils/create-patch' import { pluralizeEntry } from '../../utils/pluralize' import { SkipHandler } from '../types' +import { createScopedLogger } from '../../logger/create-scoped-logger' +import { ILogger } from '../../logger/types' type GetEntryPatchParams = { context: BaseContext @@ -13,6 +15,7 @@ type GetEntryPatchParams = { target: string entryIds: string[] entityType: EntityType + logger: ILogger } const EntityTypeMap: Record = { @@ -26,6 +29,7 @@ async function getEntityPatches({ target, entryIds, entityType, + logger, }: GetEntryPatchParams): Promise { const { client: { cda }, @@ -34,8 +38,8 @@ async function getEntityPatches({ const api = cda[entityType] - const sourceEntries = await api.getMany({ environment: source, query }).then((response) => response.items) - const targetEntries = await api.getMany({ environment: target, query }).then((response) => response.items) + const sourceEntries = await api.getMany({ environment: source, query }, logger).then((response) => response.items) + const targetEntries = await api.getMany({ environment: target, query }, logger).then((response) => response.items) const result: ChangedChangesetItem[] = [] @@ -70,7 +74,8 @@ export const createFetchChangedTasks = ({ entityType, skipHandler }: FetchChange skip: skipHandler, task: async (context: CreateChangesetContext, task) => { const { sourceEnvironmentId, affectedEntities, targetEnvironmentId, statistics, limit, changeset } = context - + const logger = createScopedLogger(context.logger, `CreateFetchChangedTasks '${entityType}'`) + logger.startScope() const entityTypeStatistics = statistics[entityType] const { @@ -99,6 +104,7 @@ export const createFetchChangedTasks = ({ entityType, skipHandler }: FetchChange target: targetEnvironmentId, entryIds: chunk, entityType, + logger, }) const withChange = changedObjects.filter((o) => o.patch.length > 0) @@ -117,6 +123,7 @@ export const createFetchChangedTasks = ({ entityType, skipHandler }: FetchChange entityTypeStatistics.added = added.length entityTypeStatistics.removed = removed.length + logger.startScope() return Promise.resolve(context) }, } diff --git a/src/engine/logger/create-scoped-logger.ts b/src/engine/logger/create-scoped-logger.ts new file mode 100644 index 000000000..662ecfaf5 --- /dev/null +++ b/src/engine/logger/create-scoped-logger.ts @@ -0,0 +1,11 @@ +import { ILogger, LogLevel } from './types' + +export function createScopedLogger(logger: ILogger, scope: string) { + const scopeStr = `[${scope}]` + return { + ...logger, + log: (level: LogLevel, message?: string | Error | undefined) => logger.log(level, `${scopeStr}\t${message}`), + startScope: () => logger.log(LogLevel.INFO, `${scopeStr}\tSTART`), + stopScope: () => logger.log(LogLevel.INFO, `${scopeStr}\tDONE`), + } +}