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

@@ -209,9 +209,9 @@ export async function deployToDevice(opts: DeviceDeployOptions): Promise<void> {
 	globalLogger.logDebug('Fetching device information...');
 	const deviceInfo = await api.getDeviceInformation();
 
-	let buildLogs: Dictionary<string> | undefined;
+	let imageIds: Dictionary<string[]> | undefined;
 	if (!opts.nolive) {
-		buildLogs = {};
+		imageIds = {};
 	}
 
 	const { awaitInterruptibleTask } = await import('../helpers');
@@ -223,7 +223,7 @@ export async function deployToDevice(opts: DeviceDeployOptions): Promise<void> {
 		deviceInfo,
 		globalLogger,
 		opts,
-		buildLogs,
+		imageIds,
 	);
 
 	globalLogger.outputDeferredMessages();
@@ -265,7 +265,7 @@ export async function deployToDevice(opts: DeviceDeployOptions): Promise<void> {
 			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<string>,
+	imageIds?: Dictionary<string[]>,
 ): Promise<BuildTask[]> {
 	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<string> = {};
+
+	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<string> {
+): Promise<string[]> {
 	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(

lib/utils/device/live.ts

@@ -52,7 +52,6 @@ interface MonitoredContainer {
 	containerId: string;
 }
 
-type BuildLogs = Dictionary<string>;
 type StageImageIDs = Dictionary<string[]>;
 
 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<void> {
@@ -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<void> {
 		// 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<string> = {};
-			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':

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