fix!: clarify the meaning of $DEBUG

Author: michaelfig

docs/env.md

@@ -49,8 +49,8 @@ Affects: agoric (CLI), ag-chain-cosmos, ag-solo
 
 Purpose: to change the meaning of `console.log` and other console methods
 
-Description: uses `anylogger` to change whether the following methods (in order
-of increasing severity) are active for a given context:
+Description: uses `anylogger` to change whether the following methods are active
+for a given context, in order of increasing severity:
 
 1. `console.debug`
 2. `console.log`
@@ -61,17 +61,16 @@ of increasing severity) are active for a given context:
 If not set, then default (`console.info` and above) logging is enabled.
 (`console.log` and `console.debug` logging is disabled.)
 
-If set to an empty string, or running in `ag-chain-cosmos start` mode, don't
-print any logs.  This is part of "consensus mode."
-
 Otherwise, set to a comma-separated list of strings.
 
 If one of those strings is
-- `agoric`, then print all console messages for the entire `agoric-sdk``.
+- `agoric:${level}`, then don't print `agoric-sdk` console messages below `${level}`.
+- `agoric:none`, then silence all `agoric-sdk` console messages.
+- `agoric` (an alias for `agoric:debug`) print all `agoric-sdk` console messages.
 - `track-turns`, then log errors at the top of the event-loop that may otherwise be unreported. See also the TRACK_TURNS environment variable below.
 - `label-instances`, then log exo instances with a unique label per instance. HAZARD This causes an information leak in the messages of thrown errors, which are available even to code without access to the console. Use with care.
 
-For each of those strings begins with a prefix recognized as indicating what
+For each of those strings beginning with a prefix recognized as indicating what
 console messages to enable, pass it to `makeConsole`. For example:
 
 - `DEBUG=SwingSet:ls` enable all console messages for liveslots, regardless of vat.

packages/agoric-cli/src/anylogger-agoric.js

@@ -2,15 +2,21 @@ import { getEnvironmentOptionsList } from '@endo/env-options';
 import anylogger from 'anylogger';
 import chalk from 'chalk';
 
-// Turn on debugging output with DEBUG=agoric
+// Turn on debugging output with DEBUG=agoric or DEBUG=agoric:${level}
 
 const DEBUG_LIST = getEnvironmentOptionsList('DEBUG');
 
 let selectedLevel = 'info';
-if (DEBUG_LIST.length === 0) {
-  selectedLevel = 'log';
-} else if (DEBUG_LIST.includes('agoric')) {
-  selectedLevel = 'debug';
+for (const level of DEBUG_LIST) {
+  const parts = level.split(':');
+  if (parts[0] !== 'agoric') {
+    continue;
+  }
+  if (parts.length > 1) {
+    selectedLevel = parts[1];
+  } else {
+    selectedLevel = 'debug';
+  }
 }
 const defaultLevel = anylogger.levels[selectedLevel];
 

packages/agoric-cli/src/cosmos.js

@@ -14,10 +14,10 @@ export default async function cosmosMain(progname, rawArgs, powers, opts) {
   const pspawnEnv = { ...process.env };
   if (popts.verbose > 1) {
     // Enable verbose logs.
-    pspawnEnv.DEBUG = 'agoric';
+    pspawnEnv.DEBUG = 'agoric:info';
   } else if (!popts.verbose) {
     // Disable more logs.
-    pspawnEnv.DEBUG = '';
+    pspawnEnv.DEBUG = 'agoric:none';
   }
 
   const pspawn = makePspawn({ env: pspawnEnv, log, spawn, chalk });

packages/agoric-cli/src/start.js

@@ -71,10 +71,10 @@ export default async function startMain(progname, rawArgs, powers, opts) {
   const pspawnEnv = { ...process.env };
   if (opts.verbose > 1) {
     // Loudly verbose logs (nondeterministic).
-    pspawnEnv.DEBUG = 'agoric,SwingSet:vat,SwingSet:ls';
+    pspawnEnv.DEBUG = 'agoric:debug,SwingSet:vat,SwingSet:ls';
   } else if (opts.verbose) {
     // Verbose vat logs (nondeterministic).
-    pspawnEnv.DEBUG = 'SwingSet:vat,SwingSet:ls';
+    pspawnEnv.DEBUG = 'agoric:info,SwingSet:vat,SwingSet:ls';
   }
 
   const pspawn = makePspawn({ env: pspawnEnv, spawn, log, chalk });

packages/agoric-cli/tools/getting-started.js

@@ -64,7 +64,7 @@ export const gettingStartedWorkflowTest = async (t, options = {}) => {
     // console.error('running agoric-cli', ...extraArgs, ...args);
     return pspawnStdout(agoricCmd[0], [...agoricCmd.slice(1), ...args], {
       stdio: ['ignore', 'pipe', 'inherit'],
-      env: { ...process.env, DEBUG: 'agoric' },
+      env: { ...process.env, DEBUG: 'agoric:debug' },
       detached: true,
       ...opts,
     });

packages/cosmic-swingset/src/anylogger-agoric.js

@@ -4,39 +4,48 @@ import anylogger from 'anylogger';
 // Turn on debugging output with DEBUG=agoric
 
 const DEBUG_LIST = getEnvironmentOptionsList('DEBUG');
-let debugging;
 
-const filterOutPrefixes = [];
-// Mute vat logging unless requested, for determinism.
-if (!DEBUG_LIST.includes('SwingSet:vat')) {
-  filterOutPrefixes.push('SwingSet:vat:');
-}
-// Mute liveSlots logging unless requested, for determinism.
-if (!DEBUG_LIST.includes('SwingSet:ls')) {
-  filterOutPrefixes.push('SwingSet:ls:');
-}
+const isVatLogNameColon = nameColon =>
+  ['SwingSet:ls:', 'SwingSet:vat:'].some(sel => nameColon.startsWith(sel));
+
+// Turn on debugging output with DEBUG=agoric or DEBUG=agoric:${level}
 
-if (DEBUG_LIST.length === 0) {
-  // DEBUG wasn't set, default to info level; quieter than normal.
-  debugging = 'info';
-} else if (DEBUG_LIST.includes('agoric')) {
-  // $DEBUG set and we're enabled; loudly verbose.
-  debugging = 'debug';
-} else {
-  // $DEBUG set but we're not enabled; slightly louder than normal.
-  debugging = 'log';
+let selectedLevel = 'info';
+for (const selector of DEBUG_LIST) {
+  const parts = selector.split(':');
+  if (parts[0] !== 'agoric') {
+    continue;
+  }
+  if (parts.length > 1) {
+    selectedLevel = parts[1];
+  } else {
+    selectedLevel = 'debug';
+  }
 }
-const defaultLevel = anylogger.levels[debugging];
+const defaultLevel = anylogger.levels[selectedLevel];
 
 const oldExt = anylogger.ext;
 anylogger.ext = (l, o) => {
   l = oldExt(l, o);
   l.enabledFor = lvl => defaultLevel >= anylogger.levels[lvl];
 
   const prefix = l.name.replace(/:/g, ': ');
-  const filteredOut = filterOutPrefixes.find(pfx => l.name.startsWith(pfx));
+
+  const nameColon = `${l.name}:`;
+  const logBelongsToVat = isVatLogNameColon(nameColon);
+
+  const logMatchesSelector = DEBUG_LIST.some(selector => {
+    const selectorColon = `${selector}:`;
+    if (!logBelongsToVat) {
+      return true;
+    }
+
+    // If this is a vat log, then it is enabled if it matches the selector.
+    return nameColon.startsWith(selectorColon);
+  });
+
   for (const [level, code] of Object.entries(anylogger.levels)) {
-    if (filteredOut || code > defaultLevel) {
+    if (!logMatchesSelector || code > defaultLevel) {
       // Disable printing.
       l[level] = () => {};
     } else {

packages/solo/src/start.js

@@ -371,12 +371,15 @@ const deployWallet = async ({ agWallet, deploys, hostport }) => {
 
   // Use the same verbosity as our caller did for us.
   let verbosity;
-  if (process.env.DEBUG === undefined || process.env.DEBUG === '') {
-    verbosity = [];
-  } else if (process.env.DEBUG.split(',').includes('agoric')) {
+  const DEBUG_LIST = (process.env.DEBUG || '').split(',');
+  if (
+    DEBUG_LIST.find(selector => ['agoric:debug', 'agoric'].includes(selector))
+  ) {
     verbosity = ['-vv'];
-  } else {
+  } else if (DEBUG_LIST.includes('agoric:info')) {
     verbosity = ['-v'];
+  } else {
+    verbosity = [];
   }
 
   // Launch the agoric wallet deploys (if any).  The assumption is that the CLI