diff --git a/core/src/graph/actions.ts b/core/src/graph/actions.ts index b8426fd9bd..aaa6b3f39e 100644 --- a/core/src/graph/actions.ts +++ b/core/src/graph/actions.ts @@ -171,7 +171,8 @@ export const actionConfigsToGraph = profileAsync(async function actionConfigsToG const preprocessActions = async (predicate: (config: ActionConfig) => boolean = () => true) => { let batchNo = 1 for (const batch of sliceToBatches(configsByKey, processingBatchSize)) { - log.debug(`Preprocessing actions batch #${batchNo} (${batch.length} items)`) + log.silly(`Preprocessing actions batch #${batchNo} (${batch.length} items)`) + const startTime = new Date().getTime() await Promise.all( batch.map(async ([key, config]) => { if (!predicate(config)) { @@ -196,6 +197,8 @@ export const actionConfigsToGraph = profileAsync(async function actionConfigsToG }) ) batchNo++ + const endTime = new Date().getTime() + log.silly(`Preprocessed actions batch #${batchNo} (${batch.length} items in ${endTime - startTime}ms`) } } @@ -291,7 +294,6 @@ export const actionConfigsToGraph = profileAsync(async function actionConfigsToG const minimalRoots = await garden.vcs.getMinimalRoots(log, allPaths) log.debug(`Found minimal roots for ${allPaths.size} paths`) - // TODO: Maybe we could optimize resolving tree versions, avoid parallel scanning of the same directory etc. const graph = new MutableConfigGraph({ environmentName: garden.environmentName, actions: [], @@ -303,7 +305,8 @@ export const actionConfigsToGraph = profileAsync(async function actionConfigsToG log.debug(`Processing ${actionConfigCount} action configs...`) let batchNo = 1 for (const batch of sliceToBatches(preprocessResults, 100)) { - log.debug(`Processing actions batch #${batchNo} (${batch.length} items)`) + log.silly(`Processing actions batch #${batchNo} (${batch.length} items)`) + const startTime = new Date().getTime() await Promise.all( batch.map(async ([key, res]) => { const { config, linkedSource, remoteSourcePath, supportedModes, dependencies } = res @@ -348,6 +351,8 @@ export const actionConfigsToGraph = profileAsync(async function actionConfigsToG }) ) batchNo++ + const endTime = new Date().getTime() + log.silly(`Processed actions batch #${batchNo} (${batch.length} items in ${endTime - startTime}ms`) } log.debug(`Processed ${actionConfigCount} action configs`) @@ -740,22 +745,25 @@ export const preprocessActionConfig = profileAsync(async function preprocessActi definition: MaybeUndefined> actionTypes: ActionDefinitionMap }): Promise { + const actionStart = new Date().getTime() const actionKey = actionReferenceToString(config) - log.debug(`Preprocessing action ${actionKey}...`) const description = describeActionConfig(config) const templateName = config.internal.templateName // in pre-processing, only use varfiles that are not template strings const resolvedVarFiles = config.varfiles?.filter((f) => !maybeTemplateString(getVarfileData(f).path)) - log.debug(`Merging variables...`) + const mergeVarsStart = new Date().getTime() const variables = await mergeVariables({ basePath: config.internal.basePath, variables: config.variables, varfiles: resolvedVarFiles, }) + const mergeVarsEnd = new Date().getTime() + const varfilesDesc = + resolvedVarFiles && resolvedVarFiles.length > 0 ? `with varfiles: \n${resolvedVarFiles.join("\n")}` : "" + log.silly(`Merged variables for action ${actionKey} in ${mergeVarsEnd - mergeVarsStart}ms ${varfilesDesc}`) - log.debug(`Resolving variables (partially)...`) const resolvedVariables = resolveTemplateStrings({ value: variables, context: new ActionConfigContext({ @@ -773,7 +781,6 @@ export const preprocessActionConfig = profileAsync(async function preprocessActi }) if (templateName) { - log.debug(`Resolving inputs (partially)...`) // Partially resolve inputs const partiallyResolvedInputs = resolveTemplateStrings({ value: config.internal.inputs || {}, @@ -871,12 +878,9 @@ export const preprocessActionConfig = profileAsync(async function preprocessActi config = { ...config, ...resolvedOther } } - log.debug(`Resolving templates...`) resolveTemplates() - log.debug(`Configuring action...`) const configureActionResult = await router.configureAction({ config, log }) - log.debug(`Action configured`) const { config: updatedConfig } = configureActionResult @@ -913,7 +917,6 @@ export const preprocessActionConfig = profileAsync(async function preprocessActi // -> Resolve templates again after configure handler // TODO: avoid this if nothing changed in the configure handler - log.debug(`Resolving templates again (for configured action)...`) try { resolveTemplates() } catch (error) { @@ -936,7 +939,6 @@ export const preprocessActionConfig = profileAsync(async function preprocessActi remoteSourcePath = config.internal.remoteClonePath } else { const key = actionReferenceToString(config) - log.debug(`Resolving external sources...`) remoteSourcePath = await garden.resolveExtSourcePath({ name: key, sourceType: "action", @@ -952,7 +954,6 @@ export const preprocessActionConfig = profileAsync(async function preprocessActi } } - log.debug(`Collecting dependencies...`) const dependencies = dependenciesFromActionConfig({ log, config, @@ -962,7 +963,9 @@ export const preprocessActionConfig = profileAsync(async function preprocessActi actionTypes, }) - log.debug(`Preprocessed action ${actionKey}...`) + const actionEnd = new Date().getTime() + log.silly(`Preprocessed action ${actionKey} in ${actionEnd - actionStart}ms`) + return { config, dependencies,