Skip to content

Commit

Permalink
Use databricks CLI log-file option to capture the logs (#923)
Browse files Browse the repository at this point in the history
## Changes
The CLI can write its logs to a file and we don't have to manage this on
the extension side.

- The format of the logs is a bit different now
- In the verbose mode we were writing debug logs to the terminal task in
the VSCode (as they were coming to the stderr). Right now such logs are
only in the log file, and output has just the stdout (as CLI keeps
stderr empty when you ask it to log to a file)
- The verbose mode option is gone. The output in the sync terminal is
clean and always based on stdout, and the verbose logs are always
written into a file


## Tests
Updated existing tests, added new unit tests
  • Loading branch information
ilia-db authored Nov 3, 2023
1 parent 7a4fb31 commit 18283bb
Show file tree
Hide file tree
Showing 9 changed files with 109 additions and 131 deletions.
1 change: 0 additions & 1 deletion packages/databricks-vscode/DATABRICKS.quickstart.md
Original file line number Diff line number Diff line change
Expand Up @@ -75,7 +75,6 @@ This extension contributes the following settings:
- `databricks.logs.maxArrayLength`: The maximum number of items to show for array fields
- `databricks.logs.enabled`: Enable/disable logging. Reload window for changes to take effect
- `databricks.clusters.onlyShowAccessibleClusters`: Only show clusters that the user has access to
- `databricks.cli.verboseMode`: Show debug logs for the sync command

## <a id="commands"></a>`Databricks:` Commands

Expand Down
5 changes: 0 additions & 5 deletions packages/databricks-vscode/package.json
Original file line number Diff line number Diff line change
Expand Up @@ -586,11 +586,6 @@
"default": false,
"description": "Enable/disable filtering for only accessible clusters (clusters on which the current user can run code)"
},
"databricks.cli.verboseMode": {
"type": "boolean",
"default": false,
"description": "Enable verbose logging for databricks CLI (sync mode)."
},
"databricks.sync.destinationType": {
"type": "string",
"default": "workspace",
Expand Down
100 changes: 64 additions & 36 deletions packages/databricks-vscode/src/cli/CliWrapper.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -5,62 +5,100 @@ import {
RemoteUri,
SyncDestinationMapper,
} from "../sync/SyncDestination";
import {workspaceConfigs} from "../vscode-objs/WorkspaceConfigs";
import {promisify} from "node:util";
import {execFile as execFileCb} from "node:child_process";
import {withFile} from "tmp-promise";
import {writeFile} from "node:fs/promises";

import {writeFile, readFile} from "node:fs/promises";
import {when, spy, reset} from "ts-mockito";
import {CliWrapper} from "./CliWrapper";
import path from "node:path";
import os from "node:os";
import crypto from "node:crypto";
import {Context} from "@databricks/databricks-sdk/dist/context";
import {logging} from "@databricks/databricks-sdk";

const execFile = promisify(execFileCb);
const cliPath = path.join(__dirname, "../../bin/databricks");

function getTempLogFilePath() {
return path.join(
os.tmpdir(),
`databricks-cli-logs-${crypto.randomUUID()}.json`
);
}

function createCliWrapper(logFilePath?: string) {
return new CliWrapper(
{
asAbsolutePath(relativePath: string) {
return path.join(__dirname, "../..", relativePath);
},
} as any,
logFilePath
);
}

describe(__filename, () => {
it("should embed a working databricks CLI", async () => {
const cliPath = __dirname + "/../../bin/databricks";
const result = await execFile(cliPath, ["--help"]);
assert.ok(result.stdout.indexOf("databricks") > 0);
});

let mocks: any[] = [];
afterEach(() => {
mocks.forEach((mock) => reset(mock));
mocks = [];
});

it("should tell CLI to log its output to a file", async () => {
const logFilePath = getTempLogFilePath();
const configsSpy = spy(workspaceConfigs);
mocks.push(configsSpy);
when(configsSpy.loggingEnabled).thenReturn(true);
const cli = createCliWrapper(logFilePath);
await execFile(cli.cliPath, ["version", ...cli.loggingArguments]);
const file = await readFile(logFilePath);
// Just checking if the file is not empty to avoid depending on internal CLI log patterns
assert.ok(file.toString().length > 0);
});

it("should create sync commands", async () => {
const cli = new CliWrapper({
asAbsolutePath(path: string) {
return path;
},
} as any);
const logFilePath = getTempLogFilePath();
const cli = createCliWrapper(logFilePath);
const mapper = new SyncDestinationMapper(
new LocalUri(
Uri.file("/Users/fabian.jakobs/Desktop/notebook-best-practices")
),
new LocalUri(Uri.file("/user/project")),
new RemoteUri(
Uri.from({
scheme: "wsfs",
path: "/Repos/fabian.jakobs@databricks.com/notebook-best-practices",
path: "/Repos/user@databricks.com/project",
})
)
);

const syncCommand = `${cliPath} sync . /Repos/[email protected]/project --watch --output json`;
const loggingArgs = `--log-level debug --log-file ${logFilePath} --log-format json`;
let {command, args} = cli.getSyncCommand(mapper, "incremental");
assert.equal(
[command, ...args].join(" "),
"./bin/databricks sync . /Repos/[email protected]/notebook-best-practices --watch --output json"
[syncCommand, loggingArgs].join(" ")
);

({command, args} = cli.getSyncCommand(mapper, "full"));
assert.equal(
[command, ...args].join(" "),
"./bin/databricks sync . /Repos/[email protected]/notebook-best-practices --watch --output json --full"
[syncCommand, loggingArgs, "--full"].join(" ")
);

const configsSpy = spy(workspaceConfigs);
mocks.push(configsSpy);
when(configsSpy.loggingEnabled).thenReturn(false);
({command, args} = cli.getSyncCommand(mapper, "incremental"));
assert.equal([command, ...args].join(" "), syncCommand);
});

it("should create an 'add profile' command", () => {
const cli = new CliWrapper({
asAbsolutePath(path: string) {
return path;
},
} as any);
const cli = createCliWrapper();

const {command, args} = cli.getAddProfileCommand(
"DEFAULT",
Expand All @@ -69,27 +107,20 @@ describe(__filename, () => {

assert.equal(
[command, ...args].join(" "),
"./bin/databricks configure --no-interactive --profile DEFAULT --host https://databricks.com/ --token"
`${cliPath} configure --no-interactive --profile DEFAULT --host https://databricks.com/ --token`
);
});

it("should list profiles when no config file exists", async () => {
const cli = new CliWrapper({
asAbsolutePath(p: string) {
return path.join(__dirname, "..", "..", p);
},
} as any);

const logFilePath = getTempLogFilePath();
const cli = createCliWrapper(logFilePath);
const profiles = await cli.listProfiles("/tmp/does-not-exist");
assert.equal(profiles.length, 0);
});

it("should list profiles", async function () {
const cli = new CliWrapper({
asAbsolutePath(p: string) {
return path.join(__dirname, "..", "..", p);
},
} as any);
const logFilePath = getTempLogFilePath();
const cli = createCliWrapper(logFilePath);

await withFile(async ({path}) => {
await writeFile(
Expand Down Expand Up @@ -121,11 +152,8 @@ describe(__filename, () => {
});

it("should load all valid profiles and return errors for rest", async () => {
const cli = new CliWrapper({
asAbsolutePath(p: string) {
return path.join(__dirname, "..", "..", p);
},
} as any);
const logFilePath = getTempLogFilePath();
const cli = createCliWrapper(logFilePath);

await withFile(async ({path}) => {
await writeFile(
Expand Down
32 changes: 26 additions & 6 deletions packages/databricks-vscode/src/cli/CliWrapper.ts
Original file line number Diff line number Diff line change
Expand Up @@ -41,12 +41,29 @@ function getValidHost(host: string) {
* of the databricks CLI
*/
export class CliWrapper {
constructor(private extensionContext: ExtensionContext) {}
constructor(
private extensionContext: ExtensionContext,
private logFilePath?: string
) {}

get cliPath(): string {
return this.extensionContext.asAbsolutePath("./bin/databricks");
}

get loggingArguments(): string[] {
if (!workspaceConfigs.loggingEnabled) {
return [];
}
return [
"--log-level",
"debug",
"--log-file",
this.logFilePath ?? "stderr",
"--log-format",
"json",
];
}

/**
* Constructs the databricks sync command
*/
Expand All @@ -61,20 +78,23 @@ export class CliWrapper {
"--watch",
"--output",
"json",
...this.loggingArguments,
];
if (syncType === "full") {
args.push("--full");
}
if (workspaceConfigs.cliVerboseMode) {
args.push("--log-level", "debug", "--log-file", "stderr");
}
return {command: this.cliPath, args};
}

private getListProfilesCommand(): Command {
return {
command: this.cliPath,
args: ["auth", "profiles", "--skip-validate"],
args: [
"auth",
"profiles",
"--skip-validate",
...this.loggingArguments,
],
};
}

Expand All @@ -83,7 +103,7 @@ export class CliWrapper {
configfilePath?: string,
@context ctx?: Context
): Promise<Array<ConfigEntry>> {
const cmd = await this.getListProfilesCommand();
const cmd = this.getListProfilesCommand();
const res = await execFile(cmd.command, cmd.args, {
env: {
/* eslint-disable @typescript-eslint/naming-convention */
Expand Down
27 changes: 0 additions & 27 deletions packages/databricks-vscode/src/cli/DatabricksCliSyncParser.ts
Original file line number Diff line number Diff line change
Expand Up @@ -3,13 +3,6 @@ import {EventEmitter} from "vscode";
import {Loggers} from "../logger";
import {SyncState} from "../sync";

const databricksLogLevelToSdk = new Map<string, logging.LEVELS>([
["DEBUG", logging.LEVELS.debug],
["INFO", logging.LEVELS.info],
["WARN", logging.LEVELS.warn],
["ERROR", logging.LEVELS.error],
]);

type EventBase = {
timestamp: string;
seq: number;
Expand Down Expand Up @@ -96,28 +89,11 @@ export class DatabricksCliSyncParser {

public processStderr(data: string) {
const logLines = data.split("\n");
let currentLogLevel: logging.LEVELS = logging.LEVELS.info;
for (let i = 0; i < logLines.length; i++) {
const line = logLines[i].trim();
if (line.length === 0) {
continue;
}

const typeMatch = line.match(
/[0-9]+(?:\/[0-9]+)+ [0-9]+(?::[0-9]+)+ \[(.+)\]/
);
if (typeMatch) {
currentLogLevel =
databricksLogLevelToSdk.get(typeMatch[1]) ??
currentLogLevel;
}
logging.NamedLogger.getOrCreate(Loggers.CLI).log(
currentLogLevel,
line,
{
outfile: "stderr",
}
);
this.writeEmitter.fire(line.trim() + "\r\n");
if (this.matchForErrors(line)) {
return;
Expand Down Expand Up @@ -154,9 +130,6 @@ export class DatabricksCliSyncParser {
if (line.length === 0) {
continue;
}
logging.NamedLogger.getOrCreate(Loggers.CLI).info(line, {
outfile: "stdout",
});

try {
this.processLine(line);
Expand Down
11 changes: 10 additions & 1 deletion packages/databricks-vscode/src/extension.ts
Original file line number Diff line number Diff line change
Expand Up @@ -143,7 +143,16 @@ export async function activate(
);

// Configuration group
const cli = new CliWrapper(context);
let cliLogFilePath;
try {
cliLogFilePath = await loggerManager.getLogFile("databricks-cli");
} catch (e) {
logging.NamedLogger.getOrCreate(Loggers.Extension).error(
"Failed to create a log file for the CLI",
e
);
}
const cli = new CliWrapper(context, cliLogFilePath);
const connectionManager = new ConnectionManager(cli, stateStorage);
context.subscriptions.push(
connectionManager.onDidChangeState(async (state) => {
Expand Down
18 changes: 6 additions & 12 deletions packages/databricks-vscode/src/logger/LoggerManager.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -26,25 +26,19 @@ describe(__filename, function () {
logging.NamedLogger.getOrCreate(Loggers.Extension).debug(
"test message"
);
logging.NamedLogger.getOrCreate(Loggers.CLI).debug("test message");

await new Promise((resolve) =>
setTimeout(
resolve,
new Time(0.5, TimeUnits.seconds).toMillSeconds().value
)
);
["sdk-and-extension-logs.json", "databricks-cli-logs.json"].forEach(
async (logfile) => {
const rawLogs = await readFile(path.join(tempDir, logfile), {
encoding: "utf-8",
});

const logs = rawLogs.split("\n");
assert.ok(logs.length !== 0);
assert.ok(logs[0].includes("test message"));
}
);
const logfile = path.join(tempDir, "sdk-and-extension-logs.json");
const rawLogs = await readFile(logfile, {encoding: "utf-8"});

const logs = rawLogs.split("\n");
assert.ok(logs.length !== 0);
assert.ok(logs[0].includes("test message"));
});

afterEach(async () => {
Expand Down
Loading

0 comments on commit 18283bb

Please sign in to comment.