fix(docutils): properly respects log levels

The resulting solution keeps a bunch of weak refs to `Consola` objects and sets the log level on all of them if it ever changes.

This is--at minimum--easier to understand than the broken `Proxy` implementation.

packages/docutils/lib/builder/deploy.ts

@@ -17,10 +17,10 @@ import {
 } from '../constants';
 import {DocutilsError} from '../error';
 import {findMkDocsYml, readPackageJson, whichMike} from '../fs';
-import logger from '../logger';
+import {getLogger} from '../logger';
 import {argify, spawnBackgroundProcess, SpawnBackgroundProcessOpts, stopwatch} from '../util';
 
-const log = logger.withTag('builder:deploy');
+const log = getLogger('builder:deploy');
 
 /**
  * Runs `mike serve`
@@ -124,6 +124,7 @@ export async function deploy({
     // unsure about how SIGHUP is handled here
     await doServe(mikeArgs, serveOpts);
   } else {
+    log.info('Deploying into branch %s', branch);
     const mikeArgs = [
       ...argify(
         _.omitBy(
@@ -138,7 +139,7 @@ export async function deploy({
     }
     await doDeploy(mikeArgs, execOpts);
 
-    log.success('Mike finished deployment into branch %s (%dms)', branch, stop());
+    log.success('Finished deployment into branch %s (%dms)', branch, stop());
   }
 }
 

packages/docutils/lib/builder/nav.ts

@@ -25,11 +25,11 @@ import {
   safeWriteFile,
   stringifyYaml,
 } from '../fs';
-import logger from '../logger';
+import {getLogger} from '../logger';
 import {MkDocsYml, MkDocsYmlNav} from '../model';
 import {relative} from '../util';
 
-const log = logger.withTag('builder:nav');
+const log = getLogger('builder:nav');
 
 /**
  * Gets a list of `.md` files relative to `docs_dir`

packages/docutils/lib/builder/reference.ts

@@ -16,10 +16,10 @@ import {
 } from '../constants';
 import {DocutilsError} from '../error';
 import {findTypeDocJsonPath, readTypedocJson} from '../fs';
-import logger from '../logger';
+import {getLogger} from '../logger';
 import {argify, relative, stopwatch} from '../util';
 
-const log = logger.withTag('builder:reference');
+const log = getLogger('builder:reference');
 
 /**
  * Executes TypeDoc _in the current process_

packages/docutils/lib/builder/site.ts

@@ -5,16 +5,15 @@
  * @module
  */
 
-import {spawn, SpawnOptions} from 'node:child_process';
 import path from 'node:path';
 import {exec, TeenProcessExecOptions} from 'teen_process';
-import {NAME_BIN, NAME_MKDOCS, NAME_MKDOCS_YML, NAME_THEME} from '../constants';
+import {NAME_BIN, NAME_MKDOCS_YML, NAME_THEME} from '../constants';
 import {DocutilsError} from '../error';
 import {findMkDocsYml, readMkDocsYml, whichMkDocs} from '../fs';
-import logger from '../logger';
+import {getLogger} from '../logger';
 import {relative, spawnBackgroundProcess, SpawnBackgroundProcessOpts, stopwatch} from '../util';
 
-const log = logger.withTag('mkdocs');
+const log = getLogger('mkdocs');
 
 /**
  * Runs `mkdocs serve`
@@ -81,6 +80,7 @@ export async function buildSite({
     // unsure about how SIGHUP is handled here
     await doServe(mkdocsArgs, serveOpts);
   } else {
+    log.info('Building site into %s (%dms)');
     await doBuild(mkdocsArgs, execOpts);
     let relSiteDir;
     if (siteDir) {
@@ -90,7 +90,7 @@ export async function buildSite({
       log.debug('Found site_dir %s', siteDir);
       relSiteDir = relative(path.dirname(mkDocsYmlPath), siteDir!);
     }
-    log.success('MkDocs finished building into %s (%dms)', relSiteDir, stop());
+    log.success('Finnished building site into %s (%dms)', relSiteDir, stop());
   }
 }
 

packages/docutils/lib/cli/check.ts

@@ -6,9 +6,9 @@
 import {fs, util} from '@appium/support';
 import _ from 'lodash';
 import type {Options} from 'yargs';
-import logger from '../logger';
+import {getLogger} from '../logger';
 
-const log = logger.withTag('check');
+const log = getLogger('check');
 
 /**
  * Given a list of objects with `id` and `path` props, filters out the ones that do not exist

packages/docutils/lib/cli/command/build.ts

@@ -7,11 +7,11 @@ import path from 'node:path';
 import type {CommandModule, InferredOptionTypes, Options} from 'yargs';
 import {buildReferenceDocs, buildSite, deploy, updateNav} from '../../builder';
 import {NAME_BIN} from '../../constants';
-import logger from '../../logger';
+import {getLogger} from '../../logger';
 import {stopwatch} from '../../util';
 import {checkMissingPaths} from '../check';
 
-const log = logger.withTag('build');
+const log = getLogger('build');
 
 enum BuildCommandGroup {
   Build = 'Build Config:',
@@ -220,6 +220,7 @@ export default {
       );
   },
   async handler(args) {
+    log.info('Building docs...');
     const stop = stopwatch('build');
     log.debug('Build command called with args: %O', args);
     if (!args.site && !args.reference) {

packages/docutils/lib/cli/command/init.ts

@@ -6,11 +6,11 @@
 import _ from 'lodash';
 import type {CommandModule, InferredOptionTypes, Options} from 'yargs';
 import {init} from '../../init';
-import logger from '../../logger';
+import {getLogger} from '../../logger';
 import {stopwatch} from '../../util';
 import {checkMissingPaths} from '../check';
 
-const log = logger.withTag('init');
+const log = getLogger('init');
 
 enum InitCommandGroup {
   MkDocs = 'MkDocs Config:',

packages/docutils/lib/cli/command/validate.ts

@@ -7,10 +7,10 @@ import {util} from '@appium/support';
 import type {CommandModule, InferredOptionTypes, Options} from 'yargs';
 import {DocutilsError} from '../../error';
 import {DocutilsValidator, ValidationKind} from '../../validate';
-import logger from '../../logger';
+import {getLogger} from '../../logger';
 import {checkMissingPaths} from '../check';
 
-const log = logger.withTag('validate');
+const log = getLogger('validate');
 
 enum ValidateCommandGroup {
   Behavior = 'Validation Behavior:',

packages/docutils/lib/cli/config.ts

@@ -11,10 +11,11 @@ import path from 'node:path';
 import YAML from 'yaml';
 import parser from 'yargs-parser';
 import {hideBin} from 'yargs/helpers';
-import {NAME_BIN} from '../constants';
-import logger from '../logger';
+import {DEFAULT_LOG_LEVEL, LogLevelMap, NAME_BIN} from '../constants';
+import {getLogger, initLogger, isLogLevelString} from '../logger';
 import {relative} from '../util';
-const log = logger.withTag('config');
+
+const log = getLogger('config');
 
 /**
  * `lilconfig` loader for YAML
@@ -43,8 +44,19 @@ const loadEsm: Loader = (filepath: string) => import(filepath);
 export async function findConfig(argv: string[] = hideBin(process.argv)) {
   const preArgs = parser(argv);
 
-  if (preArgs.verbose || preArgs.logLevel === 'debug') {
-    log.level = LogLevel.Debug;
+  // if --verbose is used, set the log level to debug.
+  // otherwise use --log-level or the default.
+  let logLevel: LogLevel | keyof typeof LogLevelMap;
+  if (preArgs.verbose) {
+    logLevel = LogLevel.Debug;
+  } else {
+    // if the loglevel is valid, use it, otherwise use the default
+    logLevel = isLogLevelString(preArgs.logLevel) ? preArgs.logLevel : DEFAULT_LOG_LEVEL;
+  }
+  initLogger(logLevel);
+
+  if (preArgs.noConfig) {
+    log.debug('Not loading config because --no-config was provided');
   }
 
   return preArgs.noConfig || preArgs.help || preArgs.version

packages/docutils/lib/cli/index.ts

@@ -6,7 +6,7 @@
  * @module
  */
 
-import logger from '../logger';
+import {getLogger} from '../logger';
 
 import _ from 'lodash';
 import {hideBin} from 'yargs/helpers';
@@ -20,7 +20,7 @@ import {sync as readPkg} from 'read-pkg';
 
 const pkg = readPkg({cwd: fs.findRoot(__dirname)});
 
-const log = logger.withTag('cli');
+const log = getLogger('cli');
 export async function main(argv = hideBin(process.argv)) {
   const config = await findConfig(argv);
 
@@ -56,24 +56,14 @@ export async function main(argv = hideBin(process.argv)) {
         describe: 'Disable config file discovery',
       },
     })
-    .middleware([
+    .middleware(
       /**
-       * Configures logging; `--verbose` implies `--log-level=debug`
+       * Writes a startup message
        */
-      (argv) => {
-        if (argv.verbose) {
-          argv.logLevel = 'debug';
-          log.debug('Debug logging enabled via --verbose');
-        }
-        log.level = LogLevelMap[argv.logLevel];
-      },
-      /**
-       * Writes a startup message, if logging is enabled
-       */
-      async () => {
+      () => {
         log.info(`${pkg.name} @ v${pkg.version} (Node.js ${process.version})`);
-      },
-    ])
+      }
+    )
     .epilog(`Please report bugs at ${pkg.bugs?.url}`)
     .fail(
       /**
@@ -85,8 +75,7 @@ export async function main(argv = hideBin(process.argv)) {
           log.error(error.message);
         } else {
           y.showHelp();
-          console.log();
-          log.error(msg ?? error.message);
+          log.error(`\n\n${msg ?? error.message}`);
         }
         y.exit(1, error);
       }

packages/docutils/lib/fs.ts

@@ -12,7 +12,7 @@ import {fs} from '@appium/support';
 import * as JSON5 from 'json5';
 import _ from 'lodash';
 import _pkgDir from 'pkg-dir';
-import logger from './logger';
+import {getLogger} from './logger';
 import {Application, TypeDocReader} from 'typedoc';
 import {
   NAME_TYPEDOC_JSON,
@@ -26,7 +26,7 @@ import {
 import {DocutilsError} from './error';
 import {MkDocsYml} from './model';
 
-const log = logger.withTag('fs');
+const log = getLogger('fs');
 
 /**
  * Finds path to closest `package.json`

packages/docutils/lib/index.ts

@@ -8,3 +8,4 @@ export * from './builder';
 export * from './validate';
 export * from './scaffold';
 export * from './constants';
+export * from './logger';

packages/docutils/lib/init.ts

@@ -17,7 +17,7 @@ import {exec} from 'teen_process';
 import {Simplify} from 'type-fest';
 import {DocutilsError} from './error';
 import {createScaffoldTask, ScaffoldTaskOptions} from './scaffold';
-import logger from './logger';
+import {getLogger} from './logger';
 import {MkDocsYml, TsConfigJson, TypeDocJson} from './model';
 import _ from 'lodash';
 import {stringifyJson5, stringifyYaml} from './fs';
@@ -54,8 +54,8 @@ const BASE_TSCONFIG_JSON: Readonly<TsConfigJson> = Object.freeze({
   },
 });
 
-const log = logger.withTag('init');
-const dryRunLog = log.withTag('dry-run');
+const log = getLogger('init');
+const dryRunLog = getLogger('dry-run', log);
 
 const DEFAULT_INCLUDE = ['lib', 'test', 'index.js'];
 /**

packages/docutils/lib/logger.ts

@@ -137,57 +137,58 @@ class DocutilsReporter extends FancyReporter {
 let globalLevel: LogLevel = LogLevelMap[DEFAULT_LOG_LEVEL];
 
 /**
- * The logger from which all loggers are created.  This one uses a unique tag and our custom reporter.
+ * Type guard to see if a string is a recognized log level
+ * @param level any value
  */
-const rootLogger = createLogProxy(
-  consola.create({defaults: {tag: 'docutils'}, reporters: [new DocutilsReporter()]})
-);
-
-/**
- * @summary Creates a log-level-propagating proxy for a {@linkcode Consola} logger.
- * @description
- * Alright.  So when you create a new logger via {@linkcode Consola.create}, it's basically a clone
- * of its parent with a new set of options.
- *
- * If we change the log level of the root logger (which we do: see `cli/index.ts`), we may (almost
- * certainly) have
- * child loggers which: a) have already been created and b) have inherited the old/default log level
- * from the root logger. We don't _want_ that (though this is likely a reasonable use case) for our
- * purposes.
- *
- * The implementation below solves the problem by maintaining its own singleton log level value, and
- * intercepts the `level` property of any logger created from the root logger.
- *
- * There are other ways to go about this which may be better, but this seemed pretty straightforward.
- */
-function createLogProxy(logger: Consola): Consola {
-  return new Proxy(logger, {
-    get(target, prop, receiver) {
-      if (prop === 'level') {
-        return globalLevel;
-      }
-      if (prop === 'create') {
-        const create = Reflect.get(target, prop, receiver) as Consola['create'];
-        return (opts: ConsolaOptions) => createLogProxy(create.call(receiver, opts));
-      }
-      if (prop === '_defaults') {
-        const defaults = Reflect.get(target, prop, receiver);
-        return {...defaults, level: globalLevel};
-      }
-      return Reflect.get(target, prop, receiver);
-    },
-    set(target, prop, value, receiver) {
-      if (prop === 'level') {
-        globalLevel = value as LogLevel;
-        return true;
-      }
-      return Reflect.set(target, prop, value, receiver);
-    },
-  });
+export function isLogLevelString(level: any): level is keyof typeof LogLevelMap {
+  return level in LogLevelMap;
 }
 
 /**
- * The proxied root logger
- * @see {createLogProxy}
+ * The logger from which all loggers are created.  This one uses a unique tag and our custom reporter.
  */
-export default rootLogger;
+const rootLogger = consola.create({
+  defaults: {tag: 'docutils'},
+  reporters: [new DocutilsReporter()],
+  level: globalLevel,
+});
+// this prevents logging before `initLogger` is called
+rootLogger.pause();
+
+/**
+ * A map of tags to loggers
+ */
+const loggers: Map<string, WeakRef<Consola>> = new Map();
+
+export function getLogger(tag: string, parent = rootLogger) {
+  if (loggers.has(tag)) {
+    const logger = loggers.get(tag)?.deref();
+    if (logger) {
+      return logger;
+    }
+  }
+  const logger = parent.withTag(tag);
+  logger.level = globalLevel;
+  loggers.set(tag, new WeakRef(logger));
+  return logger;
+}
+
+/**
+ * Initialize the logging system.
+ *
+ * This should only be called once. The loglevel cannot be changed once it is set.
+ *
+ * @remarks Child loggers seem to inherit the "paused" state of the parent, so when this is called, we must resume all of them.
+ */
+export const initLogger = _.once((level: keyof typeof LogLevelMap | LogLevel) => {
+  globalLevel = isLogLevelString(level) ? LogLevelMap[level] : level;
+  rootLogger.level = globalLevel;
+  rootLogger.resume();
+  for (const ref of loggers.values()) {
+    const logger = ref.deref();
+    if (logger) {
+      logger.level = globalLevel;
+      logger.resume();
+    }
+  }
+});

packages/docutils/lib/scaffold.ts

@@ -4,7 +4,7 @@
  */
 
 import {fs} from '@appium/support';
-import logger from './logger';
+import {getLogger} from './logger';
 import path from 'node:path';
 import {createPatch} from 'diff';
 import {NormalizedPackageJson} from 'read-pkg';
@@ -15,8 +15,8 @@ import _ from 'lodash';
 import {stringifyJson, readPackageJson, safeWriteFile} from './fs';
 import {NAME_ERR_ENOENT, NAME_ERR_EEXIST} from './constants';
 
-const log = logger.withTag('init');
-const dryRunLog = log.withTag('dry-run');
+const log = getLogger('init');
+const dryRunLog = getLogger('dry-run', log);
 
 /**
  * Creates a unified patch for display in "dry run" mode

packages/docutils/lib/validate.ts

@@ -40,7 +40,7 @@ import {
   whichPython,
   readMkDocsYml,
 } from './fs';
-import logger from './logger';
+import {getLogger} from './logger';
 import {MkDocsYml, PipPackage, TypeDocJson} from './model';
 import {relative} from './util';
 
@@ -64,7 +64,7 @@ const TYPEDOC_VERSION_REGEX = /TypeDoc\s(\d+\.\d+\..+)/;
  */
 const MKDOCS_VERSION_REGEX = /mkdocs,\s+version\s+(\d+\.\d+\.\S+)/;
 
-const log = logger.withTag('validate');
+const log = getLogger('validate');
 
 /**
  * The "kinds" of validation which were requested to be performed