feat(build): add verbose build output, progress logging, and timing for builds/tests

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<Dockerfile[]> {
-    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<Dockerfile[]> {
-    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<void> {
-    logger.log('info', 'now building Dockerfile for ' + this.cleanTag);
+  public async build(options?: { platform?: string; timeout?: number; noCache?: boolean; verbose?: boolean }): Promise<number> {
+    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<never>((_, 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<void> {
+  public async test(): Promise<number> {
+    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;
   }
 
   /**