From 578de7bcd4d1ec6a106251d19305c99c250458c1 Mon Sep 17 00:00:00 2001 From: Felipe Lalanne <1822826+pipex@users.noreply.github.com> Date: Fri, 16 Dec 2022 18:17:33 -0300 Subject: [PATCH] Process livepush build logs inline When using livepush, the CLI parses the build logs to obtain the stage image ids, which are necessary for properly running livepush. This process used to store the full log output in memory before parsing the logs for obtaining the stage ids. We have seen this cause issues before because of the excessive memory usage and it is one the suspects of #2165, which is blocking the update to Node 14 Change-type: patch --- lib/utils/device/deploy.ts | 61 ++++++++++++++++++++++++++------- lib/utils/device/live.ts | 52 +++------------------------- tests/utils/device/live.spec.ts | 2 +- 3 files changed, 55 insertions(+), 60 deletions(-) diff --git a/lib/utils/device/deploy.ts b/lib/utils/device/deploy.ts index e7d1b34c..588c723d 100644 --- a/lib/utils/device/deploy.ts +++ b/lib/utils/device/deploy.ts @@ -209,9 +209,9 @@ export async function deployToDevice(opts: DeviceDeployOptions): Promise { globalLogger.logDebug('Fetching device information...'); const deviceInfo = await api.getDeviceInformation(); - let buildLogs: Dictionary | undefined; + let imageIds: Dictionary | undefined; if (!opts.nolive) { - buildLogs = {}; + imageIds = {}; } const { awaitInterruptibleTask } = await import('../helpers'); @@ -223,7 +223,7 @@ export async function deployToDevice(opts: DeviceDeployOptions): Promise { deviceInfo, globalLogger, opts, - buildLogs, + imageIds, ); globalLogger.outputDeferredMessages(); @@ -265,7 +265,7 @@ export async function deployToDevice(opts: DeviceDeployOptions): Promise { docker, logger: globalLogger, composition: project.composition, - buildLogs: buildLogs!, + imageIds: imageIds!, deployOpts: opts, }); promises.push(livepush.init()); @@ -312,6 +312,14 @@ function connectToDocker(host: string, port: number): Docker { }); } +function extractDockerArrowMessage(outputLine: string): string | undefined { + const arrowTest = /^.*\s*-+>\s*(.+)/i; + const match = arrowTest.exec(outputLine); + if (match != null) { + return match[1]; + } +} + async function performBuilds( composition: Composition, tarStream: Readable, @@ -319,7 +327,7 @@ async function performBuilds( deviceInfo: DeviceInfo, logger: Logger, opts: DeviceDeployOptions, - buildLogs?: Dictionary, + imageIds?: Dictionary, ): Promise { const multibuild = await import('@balena/compose/dist/multibuild'); @@ -345,14 +353,29 @@ async function performBuilds( // If we're passed a build logs object make sure to set it // up properly let logHandlers: ((serviceName: string, line: string) => void) | undefined; - if (buildLogs != null) { + + const lastArrowMessage: Dictionary = {}; + + if (imageIds != null) { for (const task of buildTasks) { if (!task.external) { - buildLogs[task.serviceName] = ''; + imageIds[task.serviceName] = []; } } logHandlers = (serviceName: string, line: string) => { - buildLogs[serviceName] += `${line}\n`; + // If this was a from line, take the last found + // image id and save it + if ( + /step \d+(?:\/\d+)?\s*:\s*FROM/i.test(line) && + lastArrowMessage[serviceName] != null + ) { + imageIds[serviceName].push(lastArrowMessage[serviceName]); + } else { + const msg = extractDockerArrowMessage(line); + if (msg != null) { + lastArrowMessage[serviceName] = msg; + } + } }; } @@ -413,12 +436,26 @@ export async function rebuildSingleTask( // the logs, so any calller who wants to keep track of // this should provide the following callback containerIdCb?: (id: string) => void, -): Promise { +): Promise { const multibuild = await import('@balena/compose/dist/multibuild'); // First we run the build task, to get the new image id - let buildLogs = ''; + const stageIds = [] as string[]; + let lastArrowMessage: string | undefined; + const logHandler = (_s: string, line: string) => { - buildLogs += `${line}\n`; + // If this was a FROM line, take the last found + // image id and save it as a stage id + if ( + /step \d+(?:\/\d+)?\s*:\s*FROM/i.test(line) && + lastArrowMessage != null + ) { + stageIds.push(lastArrowMessage); + } else { + const msg = extractDockerArrowMessage(line); + if (msg != null) { + lastArrowMessage = msg; + } + } if (containerIdCb != null) { const match = line.match(/^\s*--->\s*Running\s*in\s*([a-f0-9]*)\s*$/i); @@ -477,7 +514,7 @@ export async function rebuildSingleTask( ]); } - return buildLogs; + return stageIds; } function assignOutputHandlers( diff --git a/lib/utils/device/live.ts b/lib/utils/device/live.ts index 88baaf1f..df9103a0 100644 --- a/lib/utils/device/live.ts +++ b/lib/utils/device/live.ts @@ -52,7 +52,6 @@ interface MonitoredContainer { containerId: string; } -type BuildLogs = Dictionary; type StageImageIDs = Dictionary; export interface LivepushOpts { @@ -62,7 +61,7 @@ export interface LivepushOpts { docker: Dockerode; api: DeviceAPI; logger: Logger; - buildLogs: BuildLogs; + imageIds: StageImageIDs; deployOpts: DeviceDeployOptions; } @@ -97,7 +96,7 @@ export class LivepushManager { this.api = opts.api; this.logger = opts.logger; this.deployOpts = opts.deployOpts; - this.imageIds = LivepushManager.getMultistageImageIDs(opts.buildLogs); + this.imageIds = opts.imageIds; } public async init(): Promise { @@ -297,33 +296,6 @@ export class LivepushManager { return new Dockerfile(content).generateLiveDockerfile(); } - private static getMultistageImageIDs(buildLogs: BuildLogs): StageImageIDs { - const stageIds: StageImageIDs = {}; - _.each(buildLogs, (log, serviceName) => { - stageIds[serviceName] = []; - - const lines = log.split(/\r?\n/); - let lastArrowMessage: string | undefined; - for (const line of lines) { - // If this was a from line, take the last found - // image id and save it - if ( - /step \d+(?:\/\d+)?\s*:\s*FROM/i.test(line) && - lastArrowMessage != null - ) { - stageIds[serviceName].push(lastArrowMessage); - } else { - const msg = LivepushManager.extractDockerArrowMessage(line); - if (msg != null) { - lastArrowMessage = msg; - } - } - } - }); - - return stageIds; - } - private async awaitDeviceStateSettle(): Promise { // Cache the state to avoid unnecessary calls this.lastDeviceStatus = await this.api.getStatus(); @@ -405,9 +377,9 @@ export class LivepushManager { ); } - let buildLog: string; + let stageImages: string[]; try { - buildLog = await rebuildSingleTask( + stageImages = await rebuildSingleTask( serviceName, this.docker, this.logger, @@ -466,17 +438,13 @@ export class LivepushManager { ); } - const buildLogs: Dictionary = {}; - buildLogs[serviceName] = buildLog; - const stageImages = LivepushManager.getMultistageImageIDs(buildLogs); - const dockerfile = new Dockerfile(buildTask.dockerfile!); instance.livepush = await Livepush.init({ dockerfile, context: buildTask.context!, containerId: container.containerId, - stageImages: stageImages[serviceName], + stageImages, docker: this.docker, }); this.assignLivepushOutputHandlers(serviceName, instance.livepush); @@ -536,16 +504,6 @@ export class LivepushManager { }); } - private static extractDockerArrowMessage( - outputLine: string, - ): string | undefined { - const arrowTest = /^.*\s*-+>\s*(.+)/i; - const match = arrowTest.exec(outputLine); - if (match != null) { - return match[1]; - } - } - private getDockerfilePathFromTask(task: BuildTask): string[] { switch (task.projectType) { case 'Standard Dockerfile': diff --git a/tests/utils/device/live.spec.ts b/tests/utils/device/live.spec.ts index 9a6e8441..d5414cca 100644 --- a/tests/utils/device/live.spec.ts +++ b/tests/utils/device/live.spec.ts @@ -45,7 +45,7 @@ class MockLivepushManager extends LivepushManager { docker: {} as import('dockerode'), api: {} as import('../../../lib/utils/device/api').DeviceAPI, logger: {} as import('../../../lib/utils/logger'), - buildLogs: {}, + imageIds: {}, deployOpts: {} as import('../../../lib/utils/device/deploy').DeviceDeployOptions, });