src/goDebugFactory: use --log-dest to capture dlv logs and add logDest
The old debug adapter's verbose log was written to vscode-go-debug.txt
by typescript LoggingDebugSession. Now dlv dap is replacing the old
adapter, and its verbose log messages are controlled by dlv's
--log, --log-output, and --log-dest.
dlv's --log-dest can accept a file descriptor number. This PR utilizes
it so it can cleanly distinguish delve's logging from debugee's
stdout/stderr. The logging messages with 'console' category - vscode
will present console messages with a different color so it will be
easily distinghishable from stderr/stdout.
For users who want to use dlv's --log-dest to write delve logs to a
file, this PR introduces a new debug config attribute `logDest`.
If this is set, the debug adapter writes the log message to the file
instead of showing it in DEBUG CONSOLE. (maybe we can revisit this
later and change to show the log messages in DEBUG CONSOLE as well)
This new attribute isn't supposed to be used by dlv dap or used to
set --log-dest when launching the dlv dap.
Fixes golang/vscode-go#1407
Change-Id: I8ea0a8d93fabee5c6aa5f8d5e46064d2ebd3958d
Reviewed-on: https://go-review.googlesource.com/c/vscode-go/+/313050
Trust: Hyang-Ah Hana Kim <hyangah@gmail.com>
Trust: Suzy Mueller <suzmue@golang.org>
Run-TryBot: Hyang-Ah Hana Kim <hyangah@gmail.com>
Reviewed-by: Suzy Mueller <suzmue@golang.org>
diff --git a/docs/debugging.md b/docs/debugging.md
index a66ae0d..847b66c 100644
--- a/docs/debugging.md
+++ b/docs/debugging.md
@@ -109,10 +109,11 @@
env | Environment variables to use when debugging. Use the format: `{ "NAME": "VALUE" }`. Not applicable to `attach` requests.
envFile | Absolute path to a file containing environment variable definitions. The environment variables passed in via the `env` property override the ones in this file.
args | Array of command-line arguments to pass to the program being debugged.
-showLog | If `true`, Delve logs will be printed in the Debug Console panel. This corresponds to `dlv`'s `--log` flag.
+showLog | If `true` and `logDest` is not set, Delve logs will be printed in the Debug Console panel. If `true` and `logDest` is set, logs will be written to the `logDest` file. This corresponds to `dlv`'s `--log` flag.
logOutput | Comma-separated list of Delve components (`debugger`, `gdbwire`, `lldbout`, `debuglineerr`, `rpc`) that should produce debug output when `showLog` is `true`. This corresponds to `dlv`'s `--log-output` flag.
+logDest | Absolute path to the delve log output file. This corresponds to `dlv`'s `--log-dest` flag, but number (used for file descriptor) is disallowed. Supported only in dlv-dap mode.
buildFlags | Build flags to pass to the Go compiler. This corresponds to `dlv`'s `--build-flags` flag.
-dlvFlags | Extra flags passed to `dlv`. See `dlv help` for the full list of supported flags. This is useful when users need to pass less commonly used or new flags such as `--only-same-user`, `--check-go-version`. Note that some flags such as `--log-output`, `--log`, `--init`, `--api-version` already have corresponding properties in the debug configuration, and flags such as `--listen` and `--headless` are used internally. If they are specified in `dlvFlags`, they may be ignored or cause an error.
+dlvFlags | Extra flags passed to `dlv`. See `dlv help` for the full list of supported flags. This is useful when users need to pass less commonly used or new flags such as `--only-same-user`, `--check-go-version`. Note that some flags such as `--log-output`, `--log`, `--log-dest`, `--init`, `--api-version` already have corresponding properties in the debug configuration, and flags such as `--listen` and `--headless` are used internally. If they are specified in `dlvFlags`, they may be ignored or cause an error.
remotePath | If remote debugging (`mode`: `remote`), this should be the absolute path to the package being debugged on the remote machine. See the section on [Remote Debugging](#remote-debugging) for further details. [golang/vscode-go#45](https://github.com/golang/vscode-go/issues/45) is also relevant. Becomes the first mapping in substitutePath.
substitutePath | An array of mappings from an absolute local path to an absolute remote path that is used by the debuggee. The debug adapter will replace the local path with the remote path in all of the calls. The mappings are applied in order, and the first matching mapping is used. This can be used to map files that have moved since the program was built, different remote paths, and symlinked files or directories. This is intended to be equivalent to the [substitute-path](https://github.com/go-delve/delve/tree/master/Documentation/cli#config) configuration, and will eventually configure substitute-path in Delve directly.
cwd | The working directory to be used in running the program. If remote debugging (`mode`: `remote`), this should be the absolute path to the working directory being debugged on the local machine. See the section on [Remote Debugging](#remote-debugging) for further details. [golang/vscode-go#45](https://github.com/golang/vscode-go/issues/45) is also relevant.
diff --git a/package.json b/package.json
index 8f77d60..7137c0b 100644
--- a/package.json
+++ b/package.json
@@ -598,7 +598,7 @@
},
"dlvFlags": {
"type": "array",
- "description": "Extra flags for `dlv`. See `dlv help` for the full list of supported. Flags such as `--log-output`, `--log`, `--init`, `--api-version`, `--output`, `--backend` already have corresponding properties in the debug configuration, and flags such as `--listen` and `--headless` are used internally. If they are specified in `dlvFlags`, they may be ignored or cause an error.",
+ "description": "Extra flags for `dlv`. See `dlv help` for the full list of supported. Flags such as `--log-output`, `--log`, `--log-dest`, `--init`, `--api-version`, `--output`, `--backend` already have corresponding properties in the debug configuration, and flags such as `--listen` and `--headless` are used internally. If they are specified in `dlvFlags`, they may be ignored or cause an error.",
"items": {
"type": "string"
},
@@ -670,6 +670,10 @@
"description": "Comma separated list of components that should produce debug output. Maps to dlv's `--log-output` flag. Check `dlv log` for details.",
"default": "debugger"
},
+ "logDest": {
+ "type": "string",
+ "description": "dlv's `--log-dest` flag. See `dlv log` for details. Number argument is not allowed. Supported only in dlv-dap mode."
+ },
"dlvLoadConfig": {
"type": "object",
"properties": {
@@ -771,7 +775,7 @@
},
"dlvFlags": {
"type": "array",
- "description": "Extra flags for `dlv`. See `dlv help` for the full list of supported. Flags such as `--log-output` and `--log` already have corresponding properties in the debug configuration, and flags such as `--listen` and `--headless` are used internally. If they are specified in `dlvFlags`, they may be ignored or cause an error.",
+ "description": "Extra flags for `dlv`. See `dlv help` for the full list of supported. Flags such as `--log-output`, `--log`, `--log-dest`, `--init`, `--api-version`, `--output`, `--backend` already have corresponding properties in the debug configuration, and flags such as `--listen` and `--headless` are used internally. If they are specified in `dlvFlags`, they may be ignored or cause an error.",
"items": {
"type": "string"
},
@@ -854,6 +858,10 @@
"description": "Comma separated list of components that should produce debug output. Maps to dlv's `--log-output` flag. Check `dlv log` for details.",
"default": "debugger"
},
+ "logDest": {
+ "type": "string",
+ "description": "dlv's `--log-dest` flag. See `dlv log` for details. Number argument is not allowed. Supported only in dlv-dap mode."
+ },
"dlvLoadConfig": {
"type": "object",
"properties": {
diff --git a/src/goDebugFactory.ts b/src/goDebugFactory.ts
index a970121..196ed7e 100644
--- a/src/goDebugFactory.ts
+++ b/src/goDebugFactory.ts
@@ -230,9 +230,11 @@
}, 1_000);
dlvDapServer.on('exit', (code, signal) => {
clearTimeout(exitTimeoutToken);
- this.logger?.error(
- `dlv dap process(${dlvDapServer.pid}) exited (exit code: ${code} signal: ${signal})`
- );
+ if (code || signal) {
+ this.logger?.error(
+ `dlv dap process(${dlvDapServer.pid}) exited (exit code: ${code} signal: ${signal})`
+ );
+ }
resolve();
});
});
@@ -249,7 +251,7 @@
// may not appear in the DEBUG CONSOLE. For easier debugging, log
// the messages through the logger that prints to Go Debug output
// channel.
- this.logger?.info(msg);
+ this.logger?.error(msg);
}
);
const socket = await new Promise<net.Socket>((resolve, reject) => {
@@ -341,17 +343,33 @@
if (launchArgs.logOutput) {
dlvArgs.push('--log-output=' + launchArgs.logOutput);
}
+ dlvArgs.push('--log-dest=3');
+
+ const logDest = launchArgs.logDest;
+ if (typeof logDest === 'number') {
+ logErr('Using a file descriptor for `logDest` is not allowed.');
+ throw new Error('Using a file descriptor for `logDest` is not allowed.');
+ }
+ if (logDest && !path.isAbsolute(logDest)) {
+ logErr(
+ 'Using a relative path for `logDest` is not allowed.\nSee [variables](https://code.visualstudio.com/docs/editor/variables-reference)'
+ );
+ throw new Error('Using a relative path for `logDest` is not allowed');
+ }
+ const logDestStream = logDest ? fs.createWriteStream(logDest) : undefined;
+
logConsole(`Running: ${dlvPath} ${dlvArgs.join(' ')}\n`);
const dir = parseProgramArgSync(launchArgs).dirname;
// TODO(hyangah): determine the directories:
// run `dlv` => where dlv will create the default __debug_bin. (This won't work if the directory is not writable. Fix it)
// build program => 'program' directory. (This won't work for multimodule workspace. Fix it)
- // run program => cwd or wd (If test, make sure to run in the package directory.)
+ // run program => cwd (If test, make sure to run in the package directory.)
return await new Promise<ChildProcess>((resolve, reject) => {
const p = spawn(dlvPath, dlvArgs, {
cwd: dir,
- env
+ env,
+ stdio: ['pipe', 'pipe', 'pipe', 'pipe'] // --log-dest=3
});
let started = false;
const timeoutToken: NodeJS.Timer = setTimeout(
@@ -363,6 +381,7 @@
clearTimeout(timeoutToken);
started = true;
if (err) {
+ logConsole(`Failed to start 'dlv': ${err}\nKilling the dlv process...`);
killProcessTree(p); // We do not need to wait for p to actually be killed.
reject(new Error(err));
} else {
@@ -372,19 +391,7 @@
p.stdout.on('data', (chunk) => {
if (!started) {
- // TODO(hyangah): when --log-dest is specified, the following message
- // will be written to the log dest file, not stdout/stderr.
- // Either disable --log-dest, or take advantage of it, i.e.,
- // always pass a file descriptor to --log-dest, watch the file
- // descriptor to process the log output, and also swap os.Stdout/os.Stderr
- // in dlv dap for launch requests to generate proper OutputEvents.
- if (chunk.toString().startsWith('DAP server listening at:')) {
- stopWaitingForServerToStart();
- } else {
- stopWaitingForServerToStart(
- `Expected 'DAP server listening at:' from debug adapter got '${chunk.toString()}'`
- );
- }
+ stopWaitingForServerToStart(`Unexpected output from dlv dap on start: '${chunk.toString()}'`);
}
log(chunk.toString());
});
@@ -394,6 +401,29 @@
}
logErr(chunk.toString());
});
+ p.stdio[3].on('data', (chunk) => {
+ const msg = chunk.toString();
+ if (!started) {
+ if (msg.startsWith('DAP server listening at:')) {
+ stopWaitingForServerToStart();
+ } else {
+ stopWaitingForServerToStart(`Expected 'DAP server listening at:' from debug adapter got '${msg}'`);
+ }
+ }
+ if (logDestStream) {
+ // write to the specified file.
+ logDestStream?.write(chunk, (err) => {
+ if (err) {
+ logConsole(`Error writing to ${logDest}: ${err}, log may be incomplete.`);
+ }
+ });
+ } else {
+ logConsole(msg);
+ }
+ });
+ p.stdio[3].on('close', () => {
+ logDestStream?.end();
+ });
p.on('close', (code, signal) => {
// TODO: should we watch 'exit' instead?
diff --git a/test/integration/goDebug.test.ts b/test/integration/goDebug.test.ts
index 374a3c5..29e9753 100644
--- a/test/integration/goDebug.test.ts
+++ b/test/integration/goDebug.test.ts
@@ -28,6 +28,10 @@
import { killProcessTree } from '../../src/utils/processUtils';
import getPort = require('get-port');
import util = require('util');
+import { TimestampedLogger } from '../../src/goLogging';
+
+// For debugging test and streaming the trace instead of buffering, set this.
+const PRINT_TO_CONSOLE = false;
suite('Path Manipulation Tests', () => {
test('escapeGoModPath works', () => {
@@ -1690,6 +1694,71 @@
});
});
+ suite('logDest attribute tests', () => {
+ const PROGRAM = path.join(DATA_ROOT, 'baseTest');
+
+ let tmpDir: string;
+ suiteSetup(() => {
+ tmpDir = fs.mkdtempSync(path.join(tmpdir(), 'logDestTest'));
+ });
+ suiteTeardown(() => {
+ rmdirRecursive(tmpDir);
+ });
+
+ test('logs are written to logDest file', async function () {
+ if (!isDlvDap) {
+ this.skip();
+ }
+ const DELVE_LOG = path.join(tmpDir, 'delve.log');
+ const config = {
+ name: 'Launch',
+ type: 'go',
+ request: 'launch',
+ mode: 'debug',
+ program: PROGRAM,
+ logDest: DELVE_LOG
+ };
+
+ const debugConfig = await initializeDebugConfig(config);
+ await Promise.all([dc.configurationSequence(), dc.launch(debugConfig), dc.waitForEvent('terminated')]);
+ const dapLog = fs.readFileSync(DELVE_LOG)?.toString();
+ assert(
+ dapLog.includes('DAP server listening at') &&
+ dapLog.includes('"command":"initialize"') &&
+ dapLog.includes('"event":"terminated"'),
+ dapLog
+ );
+ });
+
+ async function testWithInvalidLogDest(logDest: any, wantedErrorMessage: string) {
+ const config = {
+ name: 'Launch',
+ type: 'go',
+ request: 'launch',
+ mode: 'debug',
+ program: PROGRAM,
+ logDest
+ };
+
+ try {
+ await initializeDebugConfig(config);
+ } catch (error) {
+ assert(error?.message.includes(wantedErrorMessage), `unexpected error: ${error}`);
+ return;
+ }
+ assert.fail('dlv dap started normally, wanted the invalid logDest to cause failure');
+ }
+ test('relative path as logDest triggers an error', async function () {
+ if (!isDlvDap) this.skip();
+ await testWithInvalidLogDest('delve.log', 'relative path');
+ });
+
+ test('number as logDest triggers an error', async function () {
+ if (!isDlvDap) this.skip();
+ await testWithInvalidLogDest(3, 'file descriptor');
+ });
+ });
+
suite('substitute path', () => {
// TODO(suzmue): add unit tests for substitutePath.
let tmpDir: string;
@@ -1854,6 +1923,7 @@
// Log the output for easier test debugging.
config['logOutput'] = 'dap';
config['showLog'] = true;
+ config['trace'] = 'verbose';
}
const debugConfig = await debugConfigProvider.resolveDebugConfiguration(undefined, config);
@@ -1888,7 +1958,7 @@
}
private constructor(config: DebugConfiguration) {
- super(config);
+ super(config, new TimestampedLogger('error', undefined, PRINT_TO_CONSOLE));
}
private static TWO_CRLF = '\r\n\r\n';
@@ -1995,11 +2065,13 @@
break;
}
}
-
/* --- accumulate log messages so we can output when the test fails --- */
private _log = [] as string[];
private log(msg: string) {
this._log.push(msg);
+ if (PRINT_TO_CONSOLE) {
+ console.log(msg);
+ }
}
public printLog() {
this._log.forEach((msg) => console.log(msg));
