diff --git a/changelog.md b/changelog.md index acb8d59..e4ad49d 100644 --- a/changelog.md +++ b/changelog.md @@ -1,5 +1,15 @@ # Changelog +## 2026-02-06 - 1.9.0 - feat(build) +add verbose build output, progress logging, and timing for builds/tests + +- Add 'verbose' option to build/test flows (interfaces, CLI, and method signatures) to allow streaming raw docker build output or run silently +- Log per-item progress for build and test phases (e.g. (1/N) Building/Testing ) and report individual durations +- Return elapsed time from Dockerfile.build() and Dockerfile.test() and aggregate total build/test times in manager +- Introduce formatDuration(ms) helper in logging module to format timings +- Switch from console.log to structured logger calls across cache, manager, dockerfile and push paths +- Use silent exec variants when verbose is false and stream exec when verbose is true + ## 2026-02-06 - 1.8.0 - feat(build) add optional content-hash based build cache to skip rebuilding unchanged Dockerfiles diff --git a/ts/00_commitinfo_data.ts b/ts/00_commitinfo_data.ts index 0bc6db8..b4c5a27 100644 --- a/ts/00_commitinfo_data.ts +++ b/ts/00_commitinfo_data.ts @@ -3,6 +3,6 @@ */ export const commitinfo = { name: '@git.zone/tsdocker', - version: '1.8.0', + version: '1.9.0', description: 'develop npm modules cross platform with docker' } diff --git a/ts/classes.dockerfile.ts b/ts/classes.dockerfile.ts index 9d51618..0559da7 100644 --- a/ts/classes.dockerfile.ts +++ b/ts/classes.dockerfile.ts @@ -1,6 +1,6 @@ import * as plugins from './tsdocker.plugins.js'; import * as paths from './tsdocker.paths.js'; -import { logger } from './tsdocker.logging.js'; +import { logger, formatDuration } from './tsdocker.logging.js'; import { DockerRegistry } from './classes.dockerregistry.js'; import type { IDockerfileOptions, ITsDockerConfig, IBuildCommandOptions } from './interfaces/index.js'; import type { TsDockerManager } from './classes.tsdockermanager.js'; @@ -26,8 +26,10 @@ export class Dockerfile { .map(entry => plugins.path.join(paths.cwd, entry.name)); const readDockerfilesArray: Dockerfile[] = []; - logger.log('info', `found ${fileTree.length} Dockerfiles:`); - console.log(fileTree); + logger.log('info', `found ${fileTree.length} Dockerfile(s):`); + for (const filePath of fileTree) { + logger.log('info', ` ${plugins.path.basename(filePath)}`); + } for (const dockerfilePath of fileTree) { const myDockerfile = new Dockerfile(managerRef, { @@ -138,10 +140,18 @@ export class Dockerfile { */ public static async buildDockerfiles( sortedArrayArg: Dockerfile[], - options?: { platform?: string; timeout?: number; noCache?: boolean }, + options?: { platform?: string; timeout?: number; noCache?: boolean; verbose?: boolean }, ): Promise { - for (const dockerfileArg of sortedArrayArg) { - await dockerfileArg.build(options); + const total = sortedArrayArg.length; + const overallStart = Date.now(); + + for (let i = 0; i < total; i++) { + const dockerfileArg = sortedArrayArg[i]; + const progress = `(${i + 1}/${total})`; + logger.log('info', `${progress} Building ${dockerfileArg.cleanTag}...`); + + const elapsed = await dockerfileArg.build(options); + logger.log('ok', `${progress} Built ${dockerfileArg.cleanTag} in ${formatDuration(elapsed)}`); // Tag the built image with the full base image references used by dependent Dockerfiles, // so their FROM lines resolve to the locally-built image instead of pulling from a registry. @@ -156,6 +166,8 @@ export class Dockerfile { await smartshellInstance.exec(`docker tag ${dockerfileArg.buildTag} ${fullTag}`); } } + + logger.log('info', `Total build time: ${formatDuration(Date.now() - overallStart)}`); return sortedArrayArg; } @@ -163,9 +175,19 @@ export class Dockerfile { * Tests all Dockerfiles by calling Dockerfile.test() */ public static async testDockerfiles(sortedArrayArg: Dockerfile[]): Promise { - for (const dockerfileArg of sortedArrayArg) { - await dockerfileArg.test(); + const total = sortedArrayArg.length; + const overallStart = Date.now(); + + for (let i = 0; i < total; i++) { + const dockerfileArg = sortedArrayArg[i]; + const progress = `(${i + 1}/${total})`; + logger.log('info', `${progress} Testing ${dockerfileArg.cleanTag}...`); + + const elapsed = await dockerfileArg.test(); + logger.log('ok', `${progress} Tested ${dockerfileArg.cleanTag} in ${formatDuration(elapsed)}`); } + + logger.log('info', `Total test time: ${formatDuration(Date.now() - overallStart)}`); return sortedArrayArg; } @@ -378,13 +400,14 @@ export class Dockerfile { /** * Builds the Dockerfile */ - public async build(options?: { platform?: string; timeout?: number; noCache?: boolean }): Promise { - logger.log('info', 'now building Dockerfile for ' + this.cleanTag); + public async build(options?: { platform?: string; timeout?: number; noCache?: boolean; verbose?: boolean }): Promise { + const startTime = Date.now(); const buildArgsString = await Dockerfile.getDockerBuildArgs(this.managerRef); const config = this.managerRef.config; const platformOverride = options?.platform; const timeout = options?.timeout; const noCacheFlag = options?.noCache ? ' --no-cache' : ''; + const verbose = options?.verbose ?? false; let buildCommand: string; @@ -409,7 +432,9 @@ export class Dockerfile { if (timeout) { // Use streaming execution with timeout - const streaming = await smartshellInstance.execStreaming(buildCommand); + const streaming = verbose + ? await smartshellInstance.execStreaming(buildCommand) + : await smartshellInstance.execStreamingSilent(buildCommand); const timeoutPromise = new Promise((_, reject) => { setTimeout(() => { streaming.childProcess.kill(); @@ -422,15 +447,19 @@ export class Dockerfile { throw new Error(`Build failed for ${this.cleanTag}`); } } else { - const result = await smartshellInstance.exec(buildCommand); + const result = verbose + ? await smartshellInstance.exec(buildCommand) + : await smartshellInstance.execSilent(buildCommand); if (result.exitCode !== 0) { logger.log('error', `Build failed for ${this.cleanTag}`); - console.log(result.stdout); + if (!verbose && result.stdout) { + logger.log('error', `Build output:\n${result.stdout}`); + } throw new Error(`Build failed for ${this.cleanTag}`); } } - logger.log('ok', `Built ${this.cleanTag}`); + return Date.now() - startTime; } /** @@ -460,7 +489,7 @@ export class Dockerfile { if (inspectResult.exitCode === 0 && inspectResult.stdout.includes('@')) { const imageDigest = inspectResult.stdout.split('@')[1]?.trim(); - console.log(`The image ${this.pushTag} has digest ${imageDigest}`); + logger.log('info', `The image ${this.pushTag} has digest ${imageDigest}`); } logger.log('ok', `Pushed ${this.pushTag}`); @@ -487,15 +516,14 @@ export class Dockerfile { /** * Tests the Dockerfile by running a test script if it exists */ - public async test(): Promise { + public async test(): Promise { + const startTime = Date.now(); const testDir = this.managerRef.config.testDir || plugins.path.join(paths.cwd, 'test'); const testFile = plugins.path.join(testDir, 'test_' + this.version + '.sh'); const testFileExists = fs.existsSync(testFile); if (testFileExists) { - logger.log('info', `Running tests for ${this.cleanTag}`); - // Run tests in container await smartshellInstance.exec( `docker run --name tsdocker_test_container --entrypoint="bash" ${this.buildTag} -c "mkdir /tsdocker_test"` @@ -514,11 +542,11 @@ export class Dockerfile { if (testResult.exitCode !== 0) { throw new Error(`Tests failed for ${this.cleanTag}`); } - - logger.log('ok', `Tests passed for ${this.cleanTag}`); } else { - logger.log('warn', `Skipping tests for ${this.cleanTag} because no test file was found at ${testFile}`); + logger.log('warn', `Skipping tests for ${this.cleanTag} — no test file at ${testFile}`); } + + return Date.now() - startTime; } /** diff --git a/ts/classes.tsdockercache.ts b/ts/classes.tsdockercache.ts index a6be1fb..328e31e 100644 --- a/ts/classes.tsdockercache.ts +++ b/ts/classes.tsdockercache.ts @@ -67,23 +67,15 @@ export class TsDockerCache { const entry = this.data.entries[cleanTag]; if (!entry) { - console.log(`[cache] ${cleanTag}:`); - console.log(`[cache] Content hash: ${contentHash}`); - console.log(`[cache] Stored hash: (none)`); - console.log(`[cache] Hash match: no`); - console.log(`→ Building ${cleanTag}`); + logger.log('info', `[cache] ${cleanTag}: no cached entry, will build`); return false; } const hashMatch = entry.contentHash === contentHash; - console.log(`[cache] ${cleanTag}:`); - console.log(`[cache] Content hash: ${contentHash}`); - console.log(`[cache] Stored hash: ${entry.contentHash}`); - console.log(`[cache] Image ID: ${entry.imageId}`); - console.log(`[cache] Hash match: ${hashMatch ? 'yes' : 'no'}`); + logger.log('info', `[cache] ${cleanTag}: hash ${hashMatch ? 'matches' : 'changed'}`); if (!hashMatch) { - console.log(`→ Building ${cleanTag}`); + logger.log('info', `[cache] ${cleanTag}: content changed, will build`); return false; } @@ -92,14 +84,13 @@ export class TsDockerCache { `docker image inspect ${entry.imageId} > /dev/null 2>&1` ); const available = inspectResult.exitCode === 0; - console.log(`[cache] Available: ${available ? 'yes' : 'no'}`); if (available) { - console.log(`→ Skipping build for ${cleanTag} (cache hit)`); + logger.log('info', `[cache] ${cleanTag}: cache hit, skipping build`); return true; } - console.log(`→ Building ${cleanTag} (image no longer available)`); + logger.log('info', `[cache] ${cleanTag}: image no longer available, will build`); return false; } diff --git a/ts/classes.tsdockermanager.ts b/ts/classes.tsdockermanager.ts index ff19481..db21538 100644 --- a/ts/classes.tsdockermanager.ts +++ b/ts/classes.tsdockermanager.ts @@ -1,6 +1,6 @@ import * as plugins from './tsdocker.plugins.js'; import * as paths from './tsdocker.paths.js'; -import { logger } from './tsdocker.logging.js'; +import { logger, formatDuration } from './tsdocker.logging.js'; import { Dockerfile } from './classes.dockerfile.js'; import { DockerRegistry } from './classes.dockerregistry.js'; import { RegistryStorage } from './classes.registrystorage.js'; @@ -136,31 +136,44 @@ export class TsDockerManager { await this.ensureBuildx(); } - logger.log('info', `Building ${toBuild.length} Dockerfiles...`); + logger.log('info', ''); + logger.log('info', '=== BUILD PHASE ==='); + logger.log('info', `Building ${toBuild.length} Dockerfile(s)...`); if (options?.cached) { // === CACHED MODE: skip builds for unchanged Dockerfiles === - logger.log('info', '=== CACHED MODE ACTIVE ==='); + logger.log('info', '(cached mode active)'); const cache = new TsDockerCache(); cache.load(); - for (const dockerfileArg of toBuild) { + const total = toBuild.length; + const overallStart = Date.now(); + + for (let i = 0; i < total; i++) { + const dockerfileArg = toBuild[i]; + const progress = `(${i + 1}/${total})`; const skip = await cache.shouldSkipBuild(dockerfileArg.cleanTag, dockerfileArg.content); if (skip) { + logger.log('ok', `${progress} Skipped ${dockerfileArg.cleanTag} (cached)`); continue; } // Cache miss — build this Dockerfile - await dockerfileArg.build({ + logger.log('info', `${progress} Building ${dockerfileArg.cleanTag}...`); + const elapsed = await dockerfileArg.build({ platform: options?.platform, timeout: options?.timeout, noCache: options?.noCache, + verbose: options?.verbose, }); + logger.log('ok', `${progress} Built ${dockerfileArg.cleanTag} in ${formatDuration(elapsed)}`); const imageId = await dockerfileArg.getId(); cache.recordBuild(dockerfileArg.cleanTag, dockerfileArg.content, imageId, dockerfileArg.buildTag); } + logger.log('info', `Total build time: ${formatDuration(Date.now() - overallStart)}`); + // Perform dependency tagging for all Dockerfiles (even cache hits, since tags may be stale) for (const dockerfileArg of toBuild) { const dependentBaseImages = new Set(); @@ -182,6 +195,7 @@ export class TsDockerManager { platform: options?.platform, timeout: options?.timeout, noCache: options?.noCache, + verbose: options?.verbose, }); } @@ -308,6 +322,8 @@ export class TsDockerManager { return; } + logger.log('info', ''); + logger.log('info', '=== TEST PHASE ==='); await Dockerfile.testDockerfiles(this.dockerfiles); logger.log('success', 'All tests completed'); } @@ -320,19 +336,21 @@ export class TsDockerManager { await this.discoverDockerfiles(); } - console.log('\nDiscovered Dockerfiles:'); - console.log('========================\n'); + logger.log('info', ''); + logger.log('info', 'Discovered Dockerfiles:'); + logger.log('info', '========================'); + logger.log('info', ''); for (let i = 0; i < this.dockerfiles.length; i++) { const df = this.dockerfiles[i]; - console.log(`${i + 1}. ${df.filePath}`); - console.log(` Tag: ${df.cleanTag}`); - console.log(` Base Image: ${df.baseImage}`); - console.log(` Version: ${df.version}`); + logger.log('info', `${i + 1}. ${df.filePath}`); + logger.log('info', ` Tag: ${df.cleanTag}`); + logger.log('info', ` Base Image: ${df.baseImage}`); + logger.log('info', ` Version: ${df.version}`); if (df.localBaseImageDependent) { - console.log(` Depends on: ${df.localBaseDockerfile?.cleanTag}`); + logger.log('info', ` Depends on: ${df.localBaseDockerfile?.cleanTag}`); } - console.log(''); + logger.log('info', ''); } return this.dockerfiles; diff --git a/ts/interfaces/index.ts b/ts/interfaces/index.ts index 9269bb6..3751f78 100644 --- a/ts/interfaces/index.ts +++ b/ts/interfaces/index.ts @@ -78,6 +78,7 @@ export interface IBuildCommandOptions { timeout?: number; // Build timeout in seconds noCache?: boolean; // Force rebuild without Docker layer cache (--no-cache) cached?: boolean; // Skip builds when Dockerfile content hasn't changed + verbose?: boolean; // Stream raw docker build output (default: silent) } export interface ICacheEntry { diff --git a/ts/tsdocker.cli.ts b/ts/tsdocker.cli.ts index 16f724d..7902f10 100644 --- a/ts/tsdocker.cli.ts +++ b/ts/tsdocker.cli.ts @@ -52,6 +52,9 @@ export let run = () => { if (argvArg.cached) { buildOptions.cached = true; } + if (argvArg.verbose) { + buildOptions.verbose = true; + } await manager.build(buildOptions); logger.log('success', 'Build completed successfully'); @@ -89,6 +92,9 @@ export let run = () => { if (argvArg.cache === false) { buildOptions.noCache = true; } + if (argvArg.verbose) { + buildOptions.verbose = true; + } // Build images first (if not already built) await manager.build(buildOptions); @@ -148,6 +154,9 @@ export let run = () => { if (argvArg.cached) { buildOptions.cached = true; } + if (argvArg.verbose) { + buildOptions.verbose = true; + } await manager.build(buildOptions); // Run tests diff --git a/ts/tsdocker.logging.ts b/ts/tsdocker.logging.ts index e000016..770bab3 100644 --- a/ts/tsdocker.logging.ts +++ b/ts/tsdocker.logging.ts @@ -15,3 +15,12 @@ export const logger = new plugins.smartlog.Smartlog({ logger.addLogDestination(new plugins.smartlogDestinationLocal.DestinationLocal()); export const ora = new plugins.smartlogSouceOra.SmartlogSourceOra(); + +export function formatDuration(ms: number): string { + if (ms < 1000) return `${ms}ms`; + const totalSeconds = ms / 1000; + if (totalSeconds < 60) return `${totalSeconds.toFixed(1)}s`; + const minutes = Math.floor(totalSeconds / 60); + const seconds = Math.round(totalSeconds % 60); + return `${minutes}m ${seconds}s`; +}