diff --git a/docs/env.md b/docs/env.md index caeb85d7143..4472af2ec28 100644 --- a/docs/env.md +++ b/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` @@ -58,17 +58,22 @@ of increasing severity) are active for a given context: 4. `console.warn` 5. `console.error` -If not set, then default (`console.info` and above) logging is enabled. +If `$DEBUG` is unset or non-empty, then default (`console.log` and above) logging is enabled. (`console.debug` logging is disabled.) + +If `$DEBUG` is set to an empty string, then quiet (`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 set to a value that contains the substring `agoric`, then print all console -messages for the entire SDK. +If one of those strings is +- `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. -Otherwise, set to a comma-separated list of prefixes, where each prefix is the -context given to `makeConsole`. For example: +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. - `DEBUG=SwingSet:ls:v13` enable for liveslots in vat 13. @@ -97,6 +102,10 @@ Description: When nonempty, create pretend prepopulated tokens like "moola" and Lifetime: until chain is mature enough not to need any pretend tokens +## LOCKDOWN_* + +For the environment variables beginning with `LOCKDOWN_` , see [`lockdown` Options](https://github.com/endojs/endo/blob/master/packages/ses/docs/lockdown.md). + ## OTEL_EXPORTER_PROMETHEUS_PORT Affects: cosmic-swingset @@ -238,3 +247,8 @@ records individually. `config.defaultManagerType` has a higher priority so that tests which require a specific worker (e.g. which exercise XS heap snapshots, or metering) can override the env var, so they won't break under `yarn test:xs`. + +## TRACK_TURNS + +Log the deep causality stack behind logged errors if possible. See also the +`DEBUG` setting `DEBUG=track-turns` above. diff --git a/packages/agoric-cli/package.json b/packages/agoric-cli/package.json index ab04db47081..0eb8bc12404 100644 --- a/packages/agoric-cli/package.json +++ b/packages/agoric-cli/package.json @@ -61,6 +61,7 @@ "@endo/bundle-source": "^3.0.2", "@endo/captp": "^4.0.2", "@endo/compartment-mapper": "^1.1.0", + "@endo/env-options": "^1.1.0", "@endo/far": "^1.0.2", "@endo/init": "^1.0.2", "@endo/marshal": "^1.1.0", diff --git a/packages/agoric-cli/src/anylogger-agoric.js b/packages/agoric-cli/src/anylogger-agoric.js index 1fa42ba1e9a..2f7d6b5c303 100644 --- a/packages/agoric-cli/src/anylogger-agoric.js +++ b/packages/agoric-cli/src/anylogger-agoric.js @@ -1,31 +1,45 @@ -/* global process */ +import { + getEnvironmentOption, + getEnvironmentOptionsList, +} from '@endo/env-options'; import anylogger from 'anylogger'; import chalk from 'chalk'; -// Turn on debugging output with DEBUG=agoric -const { DEBUG } = process.env; -let selectedLevel = 'info'; -if (DEBUG === undefined) { - selectedLevel = 'log'; -} else if (DEBUG.includes('agoric')) { - selectedLevel = 'debug'; +const DEBUG_LIST = getEnvironmentOptionsList('DEBUG'); + +// Turn on debugging output with DEBUG=agoric or DEBUG=agoric:${level} +let selectedLevel = + DEBUG_LIST.length || getEnvironmentOption('DEBUG', 'unset') === 'unset' + ? 'log' + : 'info'; +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]; +const selectedCode = anylogger.levels[selectedLevel]; +const globalCode = selectedCode === undefined ? -Infinity : selectedCode; const oldExt = anylogger.ext; anylogger.ext = (l, o) => { l = oldExt(l, o); - l.enabledFor = lvl => defaultLevel >= anylogger.levels[lvl]; + l.enabledFor = lvl => globalCode >= anylogger.levels[lvl]; const prefix = l.name.replace(/:/g, ': '); for (const [level, code] of Object.entries(anylogger.levels)) { - if (code > defaultLevel) { - // Disable printing. - l[level] = () => {}; - } else { + if (globalCode >= code) { // Enable the printing with a prefix. const doLog = l[level] || (() => {}); l[level] = (...args) => doLog(chalk.bold.blue(`${prefix}:`), ...args); + } else { + // Disable printing. + l[level] = () => {}; } } return l; diff --git a/packages/agoric-cli/src/cosmos.js b/packages/agoric-cli/src/cosmos.js index cd61e70aaf1..147cda627d0 100644 --- a/packages/agoric-cli/src/cosmos.js +++ b/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 }); diff --git a/packages/agoric-cli/src/start.js b/packages/agoric-cli/src/start.js index c886ea8730e..d9aa1bcbe7e 100644 --- a/packages/agoric-cli/src/start.js +++ b/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 }); @@ -184,7 +184,7 @@ export default async function startMain(progname, rawArgs, powers, opts) { await null; if (popts.reset) { - rmVerbose(serverDir); + await rmVerbose(serverDir); } if (!opts.dockerTag) { @@ -274,7 +274,7 @@ export default async function startMain(progname, rawArgs, powers, opts) { const serverDir = `${SERVERS_ROOT_DIR}/${profileName}-${portNum}`; if (popts.reset) { - rmVerbose(serverDir); + await rmVerbose(serverDir); } let chainSpawn; @@ -481,7 +481,7 @@ export default async function startMain(progname, rawArgs, powers, opts) { } if (popts.reset) { - rmVerbose(serverDir); + await rmVerbose(serverDir); } let soloSpawn; @@ -704,7 +704,7 @@ export default async function startMain(progname, rawArgs, powers, opts) { const serverDir = `${SERVERS_ROOT_DIR}/${profileName}-${port}`; if (popts.reset) { - rmVerbose(serverDir); + await rmVerbose(serverDir); } const setupRun = (...bonusArgs) => @@ -731,7 +731,7 @@ export default async function startMain(progname, rawArgs, powers, opts) { await null; if (popts.reset) { - rmVerbose(serverDir); + await rmVerbose(serverDir); } const setupRun = (...bonusArgs) => diff --git a/packages/agoric-cli/tools/getting-started.js b/packages/agoric-cli/tools/getting-started.js index 5a4a9df8577..40ceae5f278 100644 --- a/packages/agoric-cli/tools/getting-started.js +++ b/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, }); diff --git a/packages/cosmic-swingset/package.json b/packages/cosmic-swingset/package.json index 4c19ebe13dd..09be26a5bb6 100644 --- a/packages/cosmic-swingset/package.json +++ b/packages/cosmic-swingset/package.json @@ -33,6 +33,7 @@ "@agoric/telemetry": "^0.6.2", "@agoric/vm-config": "^0.1.0", "@endo/bundle-source": "^3.0.2", + "@endo/env-options": "^1.1.0", "@endo/far": "^1.0.2", "@endo/import-bundle": "^1.0.2", "@endo/init": "^1.0.2", diff --git a/packages/cosmic-swingset/src/anylogger-agoric.js b/packages/cosmic-swingset/src/anylogger-agoric.js index 3743cffc83d..8199ddcea77 100644 --- a/packages/cosmic-swingset/src/anylogger-agoric.js +++ b/packages/cosmic-swingset/src/anylogger-agoric.js @@ -1,45 +1,55 @@ -/* global process */ +import { + getEnvironmentOptionsList, + getEnvironmentOption, +} from '@endo/env-options'; import anylogger from 'anylogger'; // Turn on debugging output with DEBUG=agoric -const { DEBUG: debugEnv = '' } = process.env; -let debugging; +const DEBUG_LIST = getEnvironmentOptionsList('DEBUG'); -const filterOutPrefixes = []; -// Mute vat logging unless requested, for determinism. -if (!debugEnv.includes('SwingSet:vat')) { - filterOutPrefixes.push('SwingSet:vat:'); -} -// Mute liveSlots logging unless requested, for determinism. -if (!debugEnv.includes('SwingSet:ls')) { - filterOutPrefixes.push('SwingSet:ls:'); -} +const isVatLogNameColon = nameColon => + ['SwingSet:ls:', 'SwingSet:vat:'].some(sel => nameColon.startsWith(sel)); -if (process.env.DEBUG === undefined) { - // DEBUG wasn't set, default to info level; quieter than normal. - debugging = 'info'; -} else if (debugEnv.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'; +// Turn on debugging output with DEBUG=agoric or DEBUG=agoric:${level} +let selectedLevel = + DEBUG_LIST.length || getEnvironmentOption('DEBUG', 'unset') === 'unset' + ? 'log' + : '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 selectedCode = anylogger.levels[selectedLevel]; +const globalCode = selectedCode === undefined ? -Infinity : selectedCode; const oldExt = anylogger.ext; anylogger.ext = (l, o) => { l = oldExt(l, o); - l.enabledFor = lvl => defaultLevel >= anylogger.levels[lvl]; + l.enabledFor = lvl => globalCode >= 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); + + // If this is a vat log, then it is enabled by a selector in DEBUG_LIST. + const logMatchesSelector = + !logBelongsToVat || + DEBUG_LIST.some(selector => { + const selectorColon = `${selector}:`; + return nameColon.startsWith(selectorColon); + }); + for (const [level, code] of Object.entries(anylogger.levels)) { - if (filteredOut || code > defaultLevel) { - // Disable printing. - l[level] = () => {}; - } else { + if (logMatchesSelector && globalCode >= code) { // Enable the printing with a prefix. const doLog = l[level]; if (doLog) { @@ -51,6 +61,9 @@ anylogger.ext = (l, o) => { } else { l[level] = () => {}; } + } else { + // Disable printing. + l[level] = () => {}; } } return l; diff --git a/packages/smart-wallet/test/test-addAsset.js b/packages/smart-wallet/test/test-addAsset.js index 87f226af64f..8f7d3f30625 100644 --- a/packages/smart-wallet/test/test-addAsset.js +++ b/packages/smart-wallet/test/test-addAsset.js @@ -38,7 +38,7 @@ test.before(async t => { t.context = await makeDefaultTestContext(t, withBankManager); }); -const DEBUG = false; +const LOG_NEWS_HEAD = false; const bigIntReplacer = (_key, val) => typeof val === 'bigint' ? Number(val) : val; @@ -68,7 +68,7 @@ test.serial('avoid O(wallets) storage writes for a new asset', async t => { const news = await E(current).subscribeAfter(publishCount); publishCount = news.publishCount; chainStorageWrites += 1; - if (DEBUG) { + if (LOG_NEWS_HEAD) { console.log(JSON.stringify(news.head, bigIntReplacer, 2)); } } diff --git a/packages/solo/src/start.js b/packages/solo/src/start.js index 291ff9ad1f3..84fa01e8a14 100644 --- a/packages/solo/src/start.js +++ b/packages/solo/src/start.js @@ -371,10 +371,13 @@ const deployWallet = async ({ agWallet, deploys, hostport }) => { // Use the same verbosity as our caller did for us. let verbosity; - if (process.env.DEBUG === undefined) { - verbosity = []; - } else if (process.env.DEBUG.includes('agoric')) { + const DEBUG_LIST = (process.env.DEBUG || '').split(','); + if ( + DEBUG_LIST.find(selector => ['agoric:debug', 'agoric'].includes(selector)) + ) { verbosity = ['-vv']; + } else if (DEBUG_LIST.includes('agoric:info') || process.env.DEBUG === '') { + verbosity = []; } else { verbosity = ['-v']; } diff --git a/packages/swingset-liveslots/package.json b/packages/swingset-liveslots/package.json index 18866dc3c6b..940ad44384d 100644 --- a/packages/swingset-liveslots/package.json +++ b/packages/swingset-liveslots/package.json @@ -20,6 +20,8 @@ "@agoric/assert": "^0.6.0", "@agoric/internal": "^0.3.2", "@agoric/store": "^0.9.2", + "@endo/env-options": "^1.1.0", + "@endo/errors": "^1.0.2", "@endo/eventual-send": "^1.1.0", "@endo/exo": "^1.1.0", "@endo/far": "^1.0.2", diff --git a/packages/swingset-liveslots/src/virtualObjectManager.js b/packages/swingset-liveslots/src/virtualObjectManager.js index 9b92d589052..1b4728559a8 100644 --- a/packages/swingset-liveslots/src/virtualObjectManager.js +++ b/packages/swingset-liveslots/src/virtualObjectManager.js @@ -1,7 +1,13 @@ /* global globalThis */ /* eslint-disable no-use-before-define, jsdoc/require-returns-type */ -import { assert, Fail } from '@agoric/assert'; +import { environmentOptionsListHas } from '@endo/env-options'; +import { + assert, + throwRedacted as Fail, + quote as q, + bare as b, +} from '@endo/errors'; import { assertPattern, mustMatch } from '@agoric/store'; import { defendPrototype, defendPrototypeKit } from '@endo/exo/tools.js'; import { Far, passStyleOf } from '@endo/marshal'; @@ -22,29 +28,9 @@ import { * @typedef {import('@endo/exo/src/exo-tools.js').KitContextProvider } KitContextProvider */ -/** - * - */ - const { hasOwn, defineProperty, getOwnPropertyNames, entries, fromEntries } = Object; const { ownKeys } = Reflect; -const { quote: q } = assert; - -// See https://github.com/Agoric/agoric-sdk/issues/8005 -// Once agoric-sdk is upgraded to depend on endo post -// https://github.com/endojs/endo/pull/1606 then remove this -// definition of `b` and say instead -// ```js -// const { quote: q, base: b } = assert; -// ``` -const b = index => q(Number(index)); - -// import { kdebug } from './kdebug.js'; - -// TODO Use environment-options.js currently in ses/src after factoring it out -// to a new package. -const env = (globalThis.process || {}).env || {}; // Turn on to give each exo instance its own toStringTag value which exposes // the SwingSet vref. @@ -53,9 +39,7 @@ const env = (globalThis.process || {}).env || {}; // confidential object-creation activity, so this must not be something // that unprivileged vat code (including unprivileged contracts) can do // for themselves. -const LABEL_INSTANCES = (env.DEBUG || '') - .split(':') - .includes('label-instances'); +const LABEL_INSTANCES = environmentOptionsListHas('DEBUG', 'label-instances'); // This file implements the "Virtual Objects" system, currently documented in // {@link https://github.com/Agoric/agoric-sdk/blob/master/packages/SwingSet/docs/virtual-objects.md}) diff --git a/yarn.lock b/yarn.lock index 5df5dc01fb8..0ea10b88acc 100644 --- a/yarn.lock +++ b/yarn.lock @@ -443,6 +443,13 @@ resolved "https://registry.yarnpkg.com/@endo/env-options/-/env-options-1.1.0.tgz#468d18c6cab6aaa5be733ba067750624ba6bac2b" integrity sha512-5D1AcZnoeaymT0yzccceyu1fbMJ7vqyrOluFC+ebVh7pDLcF5EqP27lyBdw1/GKSM60u1MOn9h9YVxmNC/Gi4A== +"@endo/errors@^1.0.2": + version "1.0.2" + resolved "https://registry.yarnpkg.com/@endo/errors/-/errors-1.0.2.tgz#dc63fc6e831004e358eca0864cb8d9d46d381bfa" + integrity sha512-OiM7RiGP/iDWruTEPiZpjiZjgzfX81NHM05GyJi2dXCiaDbg78uFcjnQaoTvxFGvETfdakZe5igzgO6zm/icvQ== + dependencies: + ses "^1.1.0" + "@endo/eslint-plugin@^2.0.1": version "2.0.1" resolved "https://registry.yarnpkg.com/@endo/eslint-plugin/-/eslint-plugin-2.0.1.tgz#178ff82f84b514ffb194cf4b91699194030506d1"