From 67c07af05749dc9bf02218b942bd82558a4cda30 Mon Sep 17 00:00:00 2001 From: Henri Normak Date: Wed, 15 Feb 2023 16:03:31 +0200 Subject: [PATCH 01/10] refactor: move determining auth config inside pullImage --- src/docker/functions/image/pull-image.ts | 6 +++--- src/generic-container/generic-container.ts | 2 -- 2 files changed, 3 insertions(+), 5 deletions(-) diff --git a/src/docker/functions/image/pull-image.ts b/src/docker/functions/image/pull-image.ts index 3d1e331f5..246bc483c 100644 --- a/src/docker/functions/image/pull-image.ts +++ b/src/docker/functions/image/pull-image.ts @@ -1,14 +1,13 @@ import { DockerImageName } from "../../../docker-image-name"; import { log } from "../../../logger"; import { PullStreamParser } from "../../pull-stream-parser"; -import { AuthConfig } from "../../types"; import { imageExists } from "./image-exists"; import Dockerode from "dockerode"; +import { getAuthConfig } from "../../../registry-auth-locator"; export type PullImageOptions = { imageName: DockerImageName; force: boolean; - authConfig?: AuthConfig; }; export const pullImage = async (dockerode: Dockerode, options: PullImageOptions): Promise => { @@ -19,7 +18,8 @@ export const pullImage = async (dockerode: Dockerode, options: PullImageOptions) } log.info(`Pulling image: ${options.imageName}`); - const stream = await dockerode.pull(options.imageName.toString(), { authconfig: options.authConfig }); + const authconfig = await getAuthConfig(options.imageName.registry); + const stream = await dockerode.pull(options.imageName.toString(), { authconfig }); await new PullStreamParser(options.imageName, log).consume(stream); } catch (err) { diff --git a/src/generic-container/generic-container.ts b/src/generic-container/generic-container.ts index f812799bf..7c38b7b05 100644 --- a/src/generic-container/generic-container.ts +++ b/src/generic-container/generic-container.ts @@ -9,7 +9,6 @@ import { DockerImageName } from "../docker-image-name"; import { StartedTestContainer, TestContainer } from "../test-container"; import { defaultWaitStrategy, WaitStrategy } from "../wait-strategy"; import { PortForwarderInstance } from "../port-forwarder"; -import { getAuthConfig } from "../registry-auth-locator"; import { BindMount, ContentToCopy, @@ -83,7 +82,6 @@ export class GenericContainer implements TestContainer { await pullImage((await dockerClient()).dockerode, { imageName: this.imageName, force: this.pullPolicy.shouldPull(), - authConfig: await getAuthConfig(this.imageName.registry), }); if (!this.imageName.isReaper()) { From 735106202cb3537705dd6c387a368ed5eb379816 Mon Sep 17 00:00:00 2001 From: Henri Normak Date: Thu, 16 Feb 2023 11:03:16 +0200 Subject: [PATCH 02/10] feat: add lock around image pulling --- src/docker/functions/image/pull-image.ts | 21 +++++++++++++-------- 1 file changed, 13 insertions(+), 8 deletions(-) diff --git a/src/docker/functions/image/pull-image.ts b/src/docker/functions/image/pull-image.ts index 246bc483c..534ec3189 100644 --- a/src/docker/functions/image/pull-image.ts +++ b/src/docker/functions/image/pull-image.ts @@ -4,24 +4,29 @@ import { PullStreamParser } from "../../pull-stream-parser"; import { imageExists } from "./image-exists"; import Dockerode from "dockerode"; import { getAuthConfig } from "../../../registry-auth-locator"; +import AsyncLock from "async-lock"; export type PullImageOptions = { imageName: DockerImageName; force: boolean; }; +const imagePullLock = new AsyncLock(); + export const pullImage = async (dockerode: Dockerode, options: PullImageOptions): Promise => { try { - if ((await imageExists(dockerode, options.imageName)) && !options.force) { - log.debug(`Not pulling image as it already exists: ${options.imageName}`); - return; - } + return imagePullLock.acquire(options.imageName.toString(), async () => { + if (!options.force && (await imageExists(dockerode, options.imageName))) { + log.debug(`Not pulling image as it already exists: ${options.imageName}`); + return; + } - log.info(`Pulling image: ${options.imageName}`); - const authconfig = await getAuthConfig(options.imageName.registry); - const stream = await dockerode.pull(options.imageName.toString(), { authconfig }); + log.info(`Pulling image: ${options.imageName}`); + const authconfig = await getAuthConfig(options.imageName.registry); + const stream = await dockerode.pull(options.imageName.toString(), { authconfig }); - await new PullStreamParser(options.imageName, log).consume(stream); + await new PullStreamParser(options.imageName, log).consume(stream); + }); } catch (err) { log.error(`Failed to pull image "${options.imageName}": ${err}`); throw err; From 02cf5781a12a50f47b3603dfe5d9374e456b1118 Mon Sep 17 00:00:00 2001 From: Henri Normak Date: Thu, 16 Feb 2023 11:03:45 +0200 Subject: [PATCH 03/10] feat: add enabled flag to logger Avoid some operations if logging is turned off --- src/log-system-diagnostics.ts | 5 +++++ src/logger.ts | 9 +++++++++ src/port-check.ts | 4 ++-- 3 files changed, 16 insertions(+), 2 deletions(-) diff --git a/src/log-system-diagnostics.ts b/src/log-system-diagnostics.ts index be4e32afc..b751c9ac7 100644 --- a/src/log-system-diagnostics.ts +++ b/src/log-system-diagnostics.ts @@ -4,6 +4,11 @@ import { getDockerInfo } from "./docker/functions/get-info"; import Dockerode from "dockerode"; export const logSystemDiagnostics = async (dockerode: Dockerode): Promise => { + if (!log.enabled) { + // Logs are not enabled, no point in doing the work of fetching the information + return; + } + log.debug("Fetching system diagnostics"); const info = { diff --git a/src/logger.ts b/src/logger.ts index d3a1f0d3b..37f04cbc8 100644 --- a/src/logger.ts +++ b/src/logger.ts @@ -3,6 +3,7 @@ import debug, { IDebugger } from "debug"; type Message = string; export interface Logger { + enabled(): boolean; trace(message: Message): void; debug(message: Message): void; info(message: Message): void; @@ -17,6 +18,10 @@ class DebugLogger implements Logger { this.logger = debug(namespace); } + public enabled(): boolean { + return this.logger.enabled; + } + public trace(message: Message): void { this.logger(`TRACE ${message}`); } @@ -45,6 +50,10 @@ export class FakeLogger implements Logger { public readonly warnLogs: Message[] = []; public readonly errorLogs: Message[] = []; + public enabled(): boolean { + return true; + } + public trace(message: Message): void { this.traceLogs.push(message); } diff --git a/src/port-check.ts b/src/port-check.ts index 3a13ce34b..7bc51dfff 100644 --- a/src/port-check.ts +++ b/src/port-check.ts @@ -47,7 +47,7 @@ export class InternalPortCheck implements PortCheck { const commandResults = await Promise.all( commands.map((command) => - execContainer(this.container, command, { stdin: true, detach: false, tty: true }, false) + execContainer(this.container, command, { stdin: true, detach: false, tty: log.enabled() }, false) ) ); const isBound = commandResults.some((result) => result.exitCode === 0); @@ -61,7 +61,7 @@ export class InternalPortCheck implements PortCheck { `The HostPortWaitStrategy will not work on a distroless image, use an alternate wait strategy for container ${this.container.id}` ); } - } else { + } else if (log.enabled()) { commandResults .map((result) => ({ ...result, output: result.output.trim() })) .filter((result) => result.exitCode !== 126 && result.output.length > 0) From 3c2c518ab9ee2b8ea703b72d022cbcd5abdb5fc1 Mon Sep 17 00:00:00 2001 From: Henri Normak Date: Thu, 16 Feb 2023 14:23:01 +0200 Subject: [PATCH 04/10] feat: cache image existance check results --- src/docker/functions/image/image-exists.ts | 20 ++++++++++++++++++-- 1 file changed, 18 insertions(+), 2 deletions(-) diff --git a/src/docker/functions/image/image-exists.ts b/src/docker/functions/image/image-exists.ts index 78c24061c..edf06d791 100644 --- a/src/docker/functions/image/image-exists.ts +++ b/src/docker/functions/image/image-exists.ts @@ -1,9 +1,25 @@ import { DockerImageName } from "../../../docker-image-name"; -import { listImages } from "./list-images"; import { log } from "../../../logger"; import Dockerode from "dockerode"; +import AsyncLock from "async-lock"; +import { listImages } from "./list-images"; + +const existingImages = new Set(); +const imageCheckLock = new AsyncLock(); export const imageExists = async (dockerode: Dockerode, imageName: DockerImageName): Promise => { log.debug(`Checking if image exists: ${imageName}`); - return (await listImages(dockerode)).some((image) => image.equals(imageName)); + + return imageCheckLock.acquire(imageName.toString(), async () => { + if (existingImages.has(imageName.toString())) { + return true; + } + + const images = await listImages(dockerode); + images.forEach((name) => { + existingImages.add(name.toString()); + }); + + return existingImages.has(imageName.toString()); + }); }; From e9a2ff54d4f4cb44536f20c0175cef62c0bc65e2 Mon Sep 17 00:00:00 2001 From: Henri Normak Date: Thu, 16 Feb 2023 15:04:01 +0200 Subject: [PATCH 05/10] fix: disable exec logging if logs are not enabled --- src/docker/functions/container/exec-container.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/docker/functions/container/exec-container.ts b/src/docker/functions/container/exec-container.ts index ba68d329f..fd40fd573 100644 --- a/src/docker/functions/container/exec-container.ts +++ b/src/docker/functions/container/exec-container.ts @@ -29,7 +29,7 @@ export const execContainer = async ( stream.on("data", (chunk) => chunks.push(chunk)); - if (shouldLog) { + if (shouldLog && execLog.enabled()) { byline(stream).on("data", (line) => execLog.trace(`${container.id}: ${line}`)); } From 4389dd87ad27d01922d15271fc27316677210de5 Mon Sep 17 00:00:00 2001 From: Henri Normak Date: Thu, 16 Feb 2023 15:31:06 +0200 Subject: [PATCH 06/10] fix: typo --- src/log-system-diagnostics.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/log-system-diagnostics.ts b/src/log-system-diagnostics.ts index b751c9ac7..5edcf33fa 100644 --- a/src/log-system-diagnostics.ts +++ b/src/log-system-diagnostics.ts @@ -4,7 +4,7 @@ import { getDockerInfo } from "./docker/functions/get-info"; import Dockerode from "dockerode"; export const logSystemDiagnostics = async (dockerode: Dockerode): Promise => { - if (!log.enabled) { + if (!log.enabled()) { // Logs are not enabled, no point in doing the work of fetching the information return; } From f01cb0d16bec965b8b4f1d29ee4364f3efbcb5bf Mon Sep 17 00:00:00 2001 From: Henri Normak Date: Thu, 16 Feb 2023 15:32:22 +0200 Subject: [PATCH 07/10] revert: re-enable tty in port-check --- src/port-check.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/port-check.ts b/src/port-check.ts index 7bc51dfff..ca8d86120 100644 --- a/src/port-check.ts +++ b/src/port-check.ts @@ -47,7 +47,7 @@ export class InternalPortCheck implements PortCheck { const commandResults = await Promise.all( commands.map((command) => - execContainer(this.container, command, { stdin: true, detach: false, tty: log.enabled() }, false) + execContainer(this.container, command, { stdin: true, detach: false, tty: true }, false) ) ); const isBound = commandResults.some((result) => result.exitCode === 0); From dce37c112132e4e498c3cfcb2bd53f9b5f50bb96 Mon Sep 17 00:00:00 2001 From: Henri Normak Date: Thu, 16 Feb 2023 15:33:10 +0200 Subject: [PATCH 08/10] refactor: move log enabled check in port-check --- src/port-check.ts | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/port-check.ts b/src/port-check.ts index ca8d86120..e9137953d 100644 --- a/src/port-check.ts +++ b/src/port-check.ts @@ -52,7 +52,7 @@ export class InternalPortCheck implements PortCheck { ); const isBound = commandResults.some((result) => result.exitCode === 0); - if (!isBound) { + if (!isBound && log.enabled()) { const shellExists = commandResults.some((result) => result.exitCode !== 126); if (!shellExists) { if (!this.isDistroless) { @@ -61,7 +61,7 @@ export class InternalPortCheck implements PortCheck { `The HostPortWaitStrategy will not work on a distroless image, use an alternate wait strategy for container ${this.container.id}` ); } - } else if (log.enabled()) { + } else { commandResults .map((result) => ({ ...result, output: result.output.trim() })) .filter((result) => result.exitCode !== 126 && result.output.length > 0) From bea27a8a5fd7e7848513c05b371a6c7a0a5c4d54 Mon Sep 17 00:00:00 2001 From: Henri Normak Date: Thu, 16 Feb 2023 15:51:05 +0200 Subject: [PATCH 09/10] test: make sure logging is enabled in port-check tests --- src/port-check.test.ts | 3 +++ 1 file changed, 3 insertions(+) diff --git a/src/port-check.test.ts b/src/port-check.test.ts index 7b0e3499a..9ba6be0cc 100644 --- a/src/port-check.test.ts +++ b/src/port-check.test.ts @@ -18,6 +18,9 @@ describe("PortCheck", () => { jest.resetAllMocks(); mockContainer = { id: "containerId" } as Dockerode.Container; portCheck = new InternalPortCheck(mockContainer); + + // Make sure logging is enabled to capture all logs + mockLogger.enabled.mockImplementation(() => true); }); it("should return true when at least one command returns exit code 0", async () => { From 68e81856f9cd034b35b924bcb72e339175efe6c9 Mon Sep 17 00:00:00 2001 From: Henri Normak Date: Fri, 17 Feb 2023 11:25:48 +0200 Subject: [PATCH 10/10] refactor: drop polling from execContainer --- .../functions/container/exec-container.ts | 42 ++++--------------- 1 file changed, 8 insertions(+), 34 deletions(-) diff --git a/src/docker/functions/container/exec-container.ts b/src/docker/functions/container/exec-container.ts index fd40fd573..f7a8e7100 100644 --- a/src/docker/functions/container/exec-container.ts +++ b/src/docker/functions/container/exec-container.ts @@ -33,8 +33,7 @@ export const execContainer = async ( byline(stream).on("data", (line) => execLog.trace(`${container.id}: ${line}`)); } - const exitCode = await waitForExec(exec); - + const exitCode = await waitForExec(exec, stream); stream.destroy(); return { output: chunks.join(""), exitCode }; @@ -59,37 +58,12 @@ const startExec = async (exec: Dockerode.Exec, options: ExecContainerOptions): P } }; -type ExecInspectResult = { - exitCode: number; - running: boolean; - entrypoint: string; - arguments: string[]; -}; - -const inspectExec = async (exec: Dockerode.Exec): Promise => { - try { - const inspectResult = await exec.inspect(); +const waitForExec = async (exec: Dockerode.Exec, stream: Readable): Promise => { + await new Promise((res, rej) => { + stream.on("end", res); + stream.on("error", rej); + }); - return { - exitCode: inspectResult.ExitCode === null ? -1 : inspectResult.ExitCode, - running: inspectResult.Running, - entrypoint: inspectResult.ProcessConfig.entrypoint, - arguments: inspectResult.ProcessConfig.arguments, - }; - } catch (err) { - log.error(`Failed to inspect exec: ${err}`); - throw err; - } + const inspectResult = await exec.inspect(); + return inspectResult.ExitCode === null ? -1 : inspectResult.ExitCode; }; - -const waitForExec = async (exec: Dockerode.Exec): Promise => - new Promise((resolve) => { - const interval = setInterval(async () => { - const { running, exitCode } = await inspectExec(exec); - - if (!running) { - clearInterval(interval); - resolve(exitCode); - } - }, 100); - });