feat: add more logging to the task system [NONE]

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<any>
         },
-        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<any>
         },
-        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<any>
         },
-        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<any>
         },
-        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<any>
         },
-        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,24 +143,27 @@ 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<any>
         },
-        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) },
           })
           return result.data as Entry<any>
         },
       },
       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) },
           })

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
     },
   }

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)
     },
   }

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
     },
   }

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>): 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
     },
   }
 }

src/engine/create-changeset/tasks/create-fetch-changed-tasks.ts

@@ -6,13 +6,16 @@ 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
   source: string
   target: string
   entryIds: string[]
   entityType: EntityType
+  logger: ILogger
 }
 
 const EntityTypeMap: Record<EntityType, 'Entry' | 'ContentType'> = {
@@ -26,6 +29,7 @@ async function getEntityPatches({
   target,
   entryIds,
   entityType,
+  logger,
 }: GetEntryPatchParams): Promise<ChangedChangesetItem[]> {
   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)
     },
   }

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`),
+  }
+}