From d7d20d2a22c2dadf540a7f744cb98735a1c90d88 Mon Sep 17 00:00:00 2001 From: Jon Edvald Date: Mon, 2 Sep 2019 18:45:39 +0200 Subject: [PATCH] feat(container): output build log while building with debug log level When using the fancy logger we only show one line at a time, but you could use the basic logger to get the full log. This should be helpful when debugging docker builds. Closes #852 --- garden-service/src/plugins/container/build.ts | 16 +++++++-- .../src/plugins/container/helpers.ts | 5 +-- .../src/plugins/kubernetes/container/build.ts | 35 ++++++++++++++++--- garden-service/src/plugins/kubernetes/run.ts | 4 +++ garden-service/src/util/ext-tools.ts | 16 +++++++-- garden-service/src/util/util.ts | 9 ++++- 6 files changed, 71 insertions(+), 14 deletions(-) diff --git a/garden-service/src/plugins/container/build.ts b/garden-service/src/plugins/container/build.ts index 0668f15319..371c3f3bb5 100644 --- a/garden-service/src/plugins/container/build.ts +++ b/garden-service/src/plugins/container/build.ts @@ -11,6 +11,9 @@ import { ContainerModule } from "./config" import { ConfigurationError } from "../../exceptions" import { GetBuildStatusParams } from "../../types/plugin/module/getBuildStatus" import { BuildModuleParams } from "../../types/plugin/module/build" +import chalk from "chalk" +import { LogLevel } from "../../logger/log-node" +import split2 = require("split2") export async function getContainerBuildStatus({ module, log }: GetBuildStatusParams) { const identifier = await containerHelpers.imageExistsLocally(module) @@ -61,10 +64,17 @@ export async function buildContainerModule({ module, log }: BuildModuleParams { }) + outputStream.on("data", (line: Buffer) => { + statusLine.setState(chalk.gray(" → " + line.toString().slice(0, 80))) + }) + const timeout = module.spec.build.timeout - const buildLog = await containerHelpers.dockerCli(module, [...cmdOpts, buildPath], { timeout }) + const buildLog = await containerHelpers.dockerCli(module, [...cmdOpts, buildPath], { outputStream, timeout }) return { fresh: true, buildLog, details: { identifier } } } diff --git a/garden-service/src/plugins/container/helpers.ts b/garden-service/src/plugins/container/helpers.ts index 94362ef7ec..0133932ec1 100644 --- a/garden-service/src/plugins/container/helpers.ts +++ b/garden-service/src/plugins/container/helpers.ts @@ -12,6 +12,7 @@ import { ConfigurationError, RuntimeError } from "../../exceptions" import { splitFirst, spawn, splitLast } from "../../util/util" import { ModuleConfig } from "../../config/module" import { ContainerModule, ContainerRegistryConfig, defaultTag, defaultNamespace, ContainerModuleConfig } from "./config" +import { Writable } from "stream" export const DEFAULT_BUILD_TIMEOUT = 600 export const minDockerVersion = "17.07.0" @@ -251,14 +252,14 @@ const helpers = { async dockerCli( module: ContainerModule, args: string[], - { timeout = DEFAULT_BUILD_TIMEOUT }: { timeout?: number } = {}, + { outputStream, timeout = DEFAULT_BUILD_TIMEOUT }: { outputStream?: Writable, timeout?: number } = {}, ) { await helpers.checkDockerVersion() const cwd = module.buildPath try { - const res = await spawn("docker", args, { cwd, timeout }) + const res = await spawn("docker", args, { cwd, outputStream, timeout }) return res.output || "" } catch (err) { throw new RuntimeError( diff --git a/garden-service/src/plugins/kubernetes/container/build.ts b/garden-service/src/plugins/kubernetes/container/build.ts index 36cae52952..41caa9ac42 100644 --- a/garden-service/src/plugins/kubernetes/container/build.ts +++ b/garden-service/src/plugins/kubernetes/container/build.ts @@ -7,6 +7,7 @@ */ import pRetry from "p-retry" +import split2 = require("split2") import { ContainerModule } from "../../container/config" import { containerHelpers } from "../../container/helpers" import { buildContainerModule, getContainerBuildStatus, getDockerBuildFlags } from "../../container/build" @@ -27,6 +28,9 @@ import { getRegistryHostname } from "../init" import { getManifestFromRegistry } from "./util" import { normalizeLocalRsyncPath } from "../../../util/fs" import { getPortForward } from "../port-forward" +import chalk from "chalk" +import { Writable } from "stream" +import { LogLevel } from "../../../logger/log-node" const dockerDaemonDeploymentName = "garden-docker-daemon" const dockerDaemonContainerName = "docker-daemon" @@ -160,6 +164,15 @@ const remoteBuild: BuildHandler = async (params) => { let buildLog = "" + // Stream debug log to a status line + const outputStream = split2() + const statusLine = log.placeholder(LogLevel.debug) + + outputStream.on("error", () => { }) + outputStream.on("data", (line: Buffer) => { + statusLine.setState(chalk.gray(" → " + line.toString().slice(0, 80))) + }) + if (provider.config.buildMode === "cluster-docker") { // Prepare the build command const dockerfilePath = posix.join(contextPath, dockerfile) @@ -175,7 +188,8 @@ const remoteBuild: BuildHandler = async (params) => { // Execute the build const podName = await getBuilderPodName(provider, log) const buildTimeout = module.spec.build.timeout - const buildRes = await execInBuilder({ provider, log, args, timeout: buildTimeout, podName }) + + const buildRes = await execInBuilder({ provider, log, args, timeout: buildTimeout, podName, outputStream }) buildLog = buildRes.stdout + buildRes.stderr // Push the image to the registry @@ -184,7 +198,7 @@ const remoteBuild: BuildHandler = async (params) => { const dockerCmd = ["docker", "push", deploymentImageId] const pushArgs = ["/bin/sh", "-c", dockerCmd.join(" ")] - const pushRes = await execInBuilder({ provider, log, args: pushArgs, timeout: 300, podName }) + const pushRes = await execInBuilder({ provider, log, args: pushArgs, timeout: 300, podName, outputStream }) buildLog += pushRes.stdout + pushRes.stderr } else { @@ -201,7 +215,7 @@ const remoteBuild: BuildHandler = async (params) => { ] // Execute the build - const buildRes = await runKaniko(provider, log, module, args) + const buildRes = await runKaniko({ provider, log, module, args, outputStream }) buildLog = buildRes.log } @@ -221,6 +235,7 @@ export interface BuilderExecParams { args: string[], timeout: number, podName: string, + outputStream?: Writable } const buildHandlers: { [mode in ContainerBuildMode]: BuildHandler } = { @@ -230,7 +245,7 @@ const buildHandlers: { [mode in ContainerBuildMode]: BuildHandler } = { } // TODO: we should make a simple service around this instead of execing into containers -export async function execInBuilder({ provider, log, args, timeout, podName }: BuilderExecParams) { +export async function execInBuilder({ provider, log, args, timeout, podName, outputStream }: BuilderExecParams) { const execCmd = ["exec", "-i", podName, "-c", dockerDaemonContainerName, "--", ...args] log.verbose(`Running: kubectl ${execCmd.join(" ")}`) @@ -241,6 +256,7 @@ export async function execInBuilder({ provider, log, args, timeout, podName }: B log, namespace: systemNamespace, timeout, + outputStream, }) } @@ -261,7 +277,15 @@ export async function getBuilderPodName(provider: KubernetesProvider, log: LogEn return builderPods[0].metadata.name } -async function runKaniko(provider: KubernetesProvider, log: LogEntry, module: ContainerModule, args: string[]) { +interface RunKanikoParams { + provider: KubernetesProvider + log: LogEntry + module: ContainerModule + args: string[] + outputStream: Writable +} + +async function runKaniko({ provider, log, module, args, outputStream }: RunKanikoParams) { const podName = `kaniko-${module.name}-${Math.round(new Date().getTime())}` const registryHostname = getRegistryHostname() @@ -325,5 +349,6 @@ async function runKaniko(provider: KubernetesProvider, log: LogEntry, module: Co }, podName, timeout: module.spec.build.timeout, + outputStream, }) } diff --git a/garden-service/src/plugins/kubernetes/run.ts b/garden-service/src/plugins/kubernetes/run.ts index 123e643a93..4ed63fb222 100644 --- a/garden-service/src/plugins/kubernetes/run.ts +++ b/garden-service/src/plugins/kubernetes/run.ts @@ -13,6 +13,7 @@ import { LogEntry } from "../../logger/log-entry" import { V1PodSpec } from "@kubernetes/client-node" import { PluginError } from "../../exceptions" import { KubernetesProvider } from "./config" +import { Writable } from "stream" interface RunPodParams { provider: KubernetesProvider, @@ -24,6 +25,7 @@ interface RunPodParams { namespace: string, annotations?: { [key: string]: string } spec: V1PodSpec, + outputStream?: Writable, podName?: string, timeout?: number, } @@ -39,6 +41,7 @@ export async function runPod( namespace, annotations, spec, + outputStream, podName, timeout, }: RunPodParams, @@ -98,6 +101,7 @@ export async function runPod( namespace, ignoreError, args: kubecmd, + outputStream, timeout, tty: interactive, }) diff --git a/garden-service/src/util/ext-tools.ts b/garden-service/src/util/ext-tools.ts index 3aa5f7b4fd..ce739df2fb 100644 --- a/garden-service/src/util/ext-tools.ts +++ b/garden-service/src/util/ext-tools.ts @@ -21,6 +21,7 @@ import { createHash } from "crypto" import * as uuid from "uuid" import * as crossSpawn from "cross-spawn" import { spawn } from "./util" +import { Writable } from "stream" const AsyncLock = require("async-lock") const toolsPath = join(GARDEN_GLOBAL_PATH, "tools") @@ -218,6 +219,7 @@ export interface ExecParams { timeout?: number input?: Buffer | string ignoreError?: boolean + outputStream?: Writable } export interface SpawnParams extends ExecParams { @@ -255,7 +257,7 @@ export class BinaryCmd extends Library { return path } - async exec({ args, cwd, env, log, timeout, input, ignoreError }: ExecParams) { + async exec({ args, cwd, env, log, timeout, input, ignoreError, outputStream }: ExecParams) { const path = await this.getPath(log) if (!args) { @@ -264,13 +266,20 @@ export class BinaryCmd extends Library { log.verbose(`Execing ${path} ${args.join(" ")}`) - return execa(path, args, { + const proc = execa(path, args, { cwd: cwd || dirname(path), timeout: this.getTimeout(timeout) * 1000, env, input, reject: !ignoreError, }) + + if (outputStream) { + proc.stdout && proc.stdout.pipe(outputStream) + proc.stderr && proc.stderr.pipe(outputStream) + } + + return proc } async stdout(params: ExecParams) { @@ -288,13 +297,14 @@ export class BinaryCmd extends Library { return crossSpawn(path, args || [], { cwd: cwd || dirname(path), env }) } - async spawnAndWait({ args, cwd, env, log, ignoreError, timeout, tty }: SpawnParams) { + async spawnAndWait({ args, cwd, env, log, ignoreError, outputStream, timeout, tty }: SpawnParams) { const path = await this.getPath(log) return spawn(path, args || [], { cwd: cwd || dirname(path), timeout: this.getTimeout(timeout), ignoreError, env, + outputStream, tty, }) } diff --git a/garden-service/src/util/util.ts b/garden-service/src/util/util.ts index f9daf3d774..02efb806ef 100644 --- a/garden-service/src/util/util.ts +++ b/garden-service/src/util/util.ts @@ -21,6 +21,7 @@ import chalk from "chalk" import { safeDump } from "js-yaml" import { createHash } from "crypto" import { tailString } from "./string" +import { Writable } from "stream" // shim to allow async generator functions if (typeof (Symbol as any).asyncIterator === "undefined") { @@ -76,6 +77,7 @@ export interface SpawnOpts { data?: Buffer ignoreError?: boolean env?: { [key: string]: string | undefined } + outputStream?: Writable tty?: boolean wait?: boolean } @@ -90,7 +92,7 @@ export interface SpawnOutput { // TODO Dump output to a log file if it exceeds the MAX_BUFFER_SIZE export function spawn(cmd: string, args: string[], opts: SpawnOpts = {}) { - const { timeout = 0, cwd, data, ignoreError = false, env, tty, wait = true } = opts + const { timeout = 0, cwd, data, ignoreError = false, env, outputStream, tty, wait = true } = opts const stdio = tty ? "inherit" : "pipe" const proc = _spawn(cmd, args, { cwd, env, stdio }) @@ -126,6 +128,11 @@ export function spawn(cmd: string, args: string[], opts: SpawnOpts = {}) { result.stderr! = tailString(result.stderr! + s, MAX_BUFFER_SIZE, true) }) + if (outputStream) { + proc.stdout!.pipe(outputStream) + proc.stderr!.pipe(outputStream) + } + if (data) { // This may happen if the spawned process errors while we're still writing data. proc.stdin!.on("error", () => { })