Skip to content

Commit

Permalink
fix: DEBUG harmony
Browse files Browse the repository at this point in the history
  • Loading branch information
erights committed Feb 3, 2024
1 parent b7a5c92 commit c10d4ed
Show file tree
Hide file tree
Showing 12 changed files with 94 additions and 69 deletions.
28 changes: 20 additions & 8 deletions docs/env.md
Original file line number Diff line number Diff line change
Expand Up @@ -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`
Expand All @@ -61,14 +61,17 @@ 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 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.
Expand Down Expand Up @@ -97,6 +100,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 envoronment 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
Expand Down Expand Up @@ -238,3 +245,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.
1 change: 1 addition & 0 deletions packages/agoric-cli/package.json
Original file line number Diff line number Diff line change
Expand Up @@ -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",
Expand Down
22 changes: 15 additions & 7 deletions packages/agoric-cli/src/anylogger-agoric.js
Original file line number Diff line number Diff line change
@@ -1,14 +1,22 @@
/* global process */
import { getEnvironmentOptionsList } from '@endo/env-options';
import anylogger from 'anylogger';
import chalk from 'chalk';

// Turn on debugging output with DEBUG=agoric
const { DEBUG } = process.env;
// Turn on debugging output with DEBUG=agoric or DEBUG=agoric:${level}

const DEBUG_LIST = getEnvironmentOptionsList('DEBUG');

let selectedLevel = 'info';
if (DEBUG === undefined) {
selectedLevel = 'log';
} else if (DEBUG.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];

Expand Down
4 changes: 2 additions & 2 deletions packages/agoric-cli/src/cosmos.js
Original file line number Diff line number Diff line change
Expand Up @@ -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 });
Expand Down
4 changes: 2 additions & 2 deletions packages/agoric-cli/src/start.js
Original file line number Diff line number Diff line change
Expand Up @@ -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 });
Expand Down
2 changes: 1 addition & 1 deletion packages/agoric-cli/tools/getting-started.js
Original file line number Diff line number Diff line change
Expand Up @@ -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,
});
Expand Down
1 change: 1 addition & 0 deletions packages/cosmic-swingset/package.json
Original file line number Diff line number Diff line change
Expand Up @@ -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",
Expand Down
57 changes: 33 additions & 24 deletions packages/cosmic-swingset/src/anylogger-agoric.js
Original file line number Diff line number Diff line change
@@ -1,42 +1,51 @@
/* global process */
import { getEnvironmentOptionsList } 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));

// Turn on debugging output with DEBUG=agoric or DEBUG=agoric:${level}

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';
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 {
Expand Down
4 changes: 2 additions & 2 deletions packages/smart-wallet/test/test-addAsset.js
Original file line number Diff line number Diff line change
Expand Up @@ -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;

Expand Down Expand Up @@ -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));
}
}
Expand Down
11 changes: 7 additions & 4 deletions packages/solo/src/start.js
Original file line number Diff line number Diff line change
Expand Up @@ -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) {
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 {
} else if (DEBUG_LIST.includes('agoric:info')) {
verbosity = ['-v'];
} else {
verbosity = [];
}

// Launch the agoric wallet deploys (if any). The assumption is that the CLI
Expand Down
1 change: 1 addition & 0 deletions packages/swingset-liveslots/package.json
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,7 @@
"@agoric/assert": "^0.6.0",
"@agoric/internal": "^0.3.2",
"@agoric/store": "^0.9.2",
"@endo/env-options": "^1.1.0",
"@endo/eventual-send": "^1.1.0",
"@endo/exo": "^1.1.0",
"@endo/far": "^1.0.2",
Expand Down
28 changes: 9 additions & 19 deletions packages/swingset-liveslots/src/virtualObjectManager.js
Original file line number Diff line number Diff line change
@@ -1,6 +1,7 @@
/* global globalThis */
/* eslint-disable no-use-before-define, jsdoc/require-returns-type */

import { environmentOptionsListHas } from '@endo/env-options';
import { assert, Fail } from '@agoric/assert';
import { assertPattern, mustMatch } from '@agoric/store';
import { defendPrototype, defendPrototypeKit } from '@endo/exo/tools.js';
Expand All @@ -14,6 +15,9 @@ import {
checkAndUpdateFacetiousness,
} from './facetiousness.js';

// TODO Why is this here but commented out? If no longer relevant, remove
// import { kdebug } from './kdebug.js';

/** @template T @typedef {import('@agoric/vat-data').DefineKindOptions<T>} DefineKindOptions */

/**
Expand All @@ -29,22 +33,10 @@ import {
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 || {};
// TODO https://github.com/Agoric/agoric-sdk/issues/8005
// TODO https://github.com/endojs/endo/issues/1703
// @ts-expect-error
const { quote: q, bare: b } = assert;

// Turn on to give each exo instance its own toStringTag value which exposes
// the SwingSet vref.
Expand All @@ -53,9 +45,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})
Expand Down

0 comments on commit c10d4ed

Please sign in to comment.