Merge pull request #2396 from balena-os/switch-to-image-pull-if-delta-failure

Switch to image pull if delta failure

package-lock.json

@@ -58,7 +58,7 @@
         "copy-webpack-plugin": "^12.0.0",
         "deep-object-diff": "1.1.0",
         "docker-delta": "^4.1.0",
-        "docker-progress": "^5.2.3",
+        "docker-progress": "^5.2.4",
         "dockerode": "^4.0.2",
         "duration-js": "^4.0.0",
         "express": "^4.21.2",
@@ -4794,10 +4794,11 @@
       }
     },
     "node_modules/docker-progress": {
-      "version": "5.2.3",
-      "resolved": "https://registry.npmjs.org/docker-progress/-/docker-progress-5.2.3.tgz",
-      "integrity": "sha512-tsiqpC61pzaDOkKhbvr7ABQB2bL3bx+sVa7r4IZFf3tzwcMIhcU/sr5fqsXOKzIspxiCL+UHNS9gNO5ly9JxWg==",
+      "version": "5.2.4",
+      "resolved": "https://registry.npmjs.org/docker-progress/-/docker-progress-5.2.4.tgz",
+      "integrity": "sha512-sgEXTJh78YOj8pIBIzZHLo3KpamJ5N0/3pU7DkpZBBvxZ9PmO0d9ND6x7TExQZf4hgvlFRBS41aN+GHx6vu5KQ==",
       "dev": true,
+      "license": "Apache-2.0",
       "dependencies": {
         "@types/dockerode": "^3.3.23",
         "JSONStream": "^1.3.5",

package.json

@@ -84,7 +84,7 @@
     "copy-webpack-plugin": "^12.0.0",
     "deep-object-diff": "1.1.0",
     "docker-delta": "^4.1.0",
-    "docker-progress": "^5.2.3",
+    "docker-progress": "^5.2.4",
     "dockerode": "^4.0.2",
     "duration-js": "^4.0.0",
     "express": "^4.21.2",

src/lib/docker-utils.ts

@@ -1,22 +1,23 @@
-import type { ProgressCallback } from 'docker-progress';
 import { DockerProgress } from 'docker-progress';
+import type { ProgressCallback } from 'docker-progress';
 import Dockerode from 'dockerode';
 import _ from 'lodash';
 import memoizee from 'memoizee';
-
 import { applyDelta, OutOfSyncError } from 'docker-delta';
 
-import type { SchemaReturn } from '../config/schema-type';
+import log from './supervisor-console';
 import { envArrayToObject } from './conversions';
+import * as request from './request';
 import {
 	DeltaStillProcessingError,
 	ImageAuthenticationError,
 	InvalidNetGatewayError,
+	DeltaServerError,
+	DeltaApplyError,
+	isStatusError,
 } from './errors';
-import * as request from './request';
 import type { EnvVarObject } from '../types';
-
-import log from './supervisor-console';
+import type { SchemaReturn } from '../config/schema-type';
 
 export type FetchOptions = SchemaReturn<'fetchOptions'>;
 export type DeltaFetchOptions = FetchOptions & {
@@ -41,6 +42,18 @@ type ImageNameParts = {
 // (10 mins)
 const DELTA_TOKEN_TIMEOUT = 10 * 60 * 1000;
 
+// How many times to retry a v3 delta apply before falling back to a regular pull.
+// A delta is applied to the base image when pulling, so a failure could be due to
+// "layers from manifest don't match image configuration", which can occur before
+// or after downloading delta image layers.
+//
+// Other causes of failure have not been documented as clearly as "layers from manifest"
+// but could manifest as well, though unclear if they occur before, after, or during
+// downloading delta image layers.
+//
+// See: https://github.com/balena-os/balena-engine/blob/master/distribution/pull_v2.go#L43
+const DELTA_APPLY_RETRY_COUNT = 3;
+
 export const docker = new Dockerode();
 export const dockerProgress = new DockerProgress({
 	docker,
@@ -113,11 +126,7 @@ export async function fetchDeltaWithProgress(
 	onProgress: ProgressCallback,
 	serviceName: string,
 ): Promise<string> {
-	const deltaSourceId =
-		deltaOpts.deltaSourceId != null
-			? deltaOpts.deltaSourceId
-			: deltaOpts.deltaSource;
-
+	const deltaSourceId = deltaOpts.deltaSourceId ?? deltaOpts.deltaSource;
 	const timeout = deltaOpts.deltaApplyTimeout;
 
 	const logFn = (str: string) =>
@@ -143,7 +152,7 @@ export async function fetchDeltaWithProgress(
 	}
 
 	// Since the supevisor never calls this function with a source anymore,
-	// this should never happen, but w ehandle it anyway
+	// this should never happen, but we handle it anyway
 	if (deltaOpts.deltaSource == null) {
 		logFn('Falling back to regular pull due to lack of a delta source');
 		return fetchImageWithProgress(imgDest, deltaOpts, onProgress);
@@ -210,6 +219,10 @@ export async function fetchDeltaWithProgress(
 				}
 				break;
 			case 3:
+				// If 400s status code, throw a more specific error & revert immediately to a regular pull
+				if (res.statusCode >= 400 && res.statusCode < 500) {
+					throw new DeltaServerError(res.statusCode, res.statusMessage);
+				}
 				if (res.statusCode !== 200) {
 					throw new Error(
 						`Got ${res.statusCode} when requesting v3 delta from delta server.`,
@@ -225,24 +238,62 @@ export async function fetchDeltaWithProgress(
 							`Got an error when parsing delta server response for v3 delta: ${e}`,
 						);
 					}
-					id = await applyBalenaDelta(name, token, onProgress, logFn);
+					// Try to apply delta DELTA_APPLY_RETRY_COUNT times, then throw DeltaApplyError
+					let lastError: Error | undefined = undefined;
+					for (
+						let tryCount = 0;
+						tryCount < DELTA_APPLY_RETRY_COUNT;
+						tryCount++
+					) {
+						try {
+							id = await applyBalenaDelta(name, token, onProgress, logFn);
+							break;
+						} catch (e) {
+							if (isStatusError(e)) {
+								// A status error during delta pull indicates network issues,
+								// so we should throw an error to the handler that indicates that
+								// the delta pull should be retried until network issues are resolved,
+								// rather than falling back to a regular pull.
+								throw e;
+							}
+							lastError = e as Error;
+							logFn(
+								`Delta apply failed, retrying (${tryCount + 1}/${DELTA_APPLY_RETRY_COUNT})...`,
+							);
+						}
+					}
+					if (lastError) {
+						throw new DeltaApplyError(lastError.message);
+					}
 				}
 				break;
 			default:
 				throw new Error(`Unsupported delta version: ${deltaOpts.deltaVersion}`);
 		}
 	} catch (e) {
+		// Log appropriate message based on error type
 		if (e instanceof OutOfSyncError) {
 			logFn('Falling back to regular pull due to delta out of sync error');
-			return await fetchImageWithProgress(imgDest, deltaOpts, onProgress);
+		} else if (e instanceof DeltaServerError) {
+			logFn(
+				`Falling back to regular pull due to delta server error (${e.statusCode})${e.statusMessage ? `: ${e.statusMessage}` : ''}`,
+			);
+		} else if (e instanceof DeltaApplyError) {
+			// A delta apply error is raised from the Engine and doesn't have a status code
+			logFn(
+				`Falling back to regular pull due to delta apply error ${e.message ? `: ${e.message}` : ''}`,
+			);
 		} else {
 			logFn(`Delta failed with ${e}`);
 			throw e;
 		}
+
+		// For handled errors, fall back to regular pull
+		return fetchImageWithProgress(imgDest, deltaOpts, onProgress);
 	}
 
 	logFn(`Delta applied successfully`);
-	return id;
+	return id!;
 }
 
 export async function fetchImageWithProgress(

src/lib/errors.ts

@@ -70,6 +70,13 @@ export class InvalidNetGatewayError extends TypedError {}
 
 export class DeltaStillProcessingError extends TypedError {}
 
+export class DeltaServerError extends StatusError {}
+export class DeltaApplyError extends Error {
+	constructor(message?: string) {
+		super(message);
+	}
+}
+
 export class UpdatesLockedError extends TypedError {}
 
 export function isHttpConflictError(err: { statusCode: number }): boolean {