Save log files to the query history directory

This commit deprecates the the cutsom log directory option by saving
all log files with query history.

There is a simplification of the `OutputChannelLogger` since it no
longer needs to manage deleting log files on exit.

Also, the `codeQL.runningQueries.customLogDirectory` is marked as
deprecated. If this value is being used, a warning message is popped
up after the query completes.
This commit is contained in:
Andrew Eisenberg 2022-03-01 08:58:46 -08:00
Родитель c18f7953e7
Коммит 2579d12f24
7 изменённых файлов: 74 добавлений и 196 удалений

Просмотреть файл

@ -5,6 +5,7 @@
- Fix a bug where database upgrades could not be resolved if some of the target pack's dependencies are outside of the workspace. [#1138](https://github.com/github/vscode-codeql/pull/1138)
- Open the query server logs for query errors (instead of the extension log). This will make it easier to track down query errors. [#1158](https://github.com/github/vscode-codeql/pull/1158)
- Fix a bug where queries took a long time to run if there are no folders in the workspace. [#1157](https://github.com/github/vscode-codeql/pull/1157)
- [BREAKING CHANGE] The `codeQL.runningQueries.customLogDirectory` setting is deprecated and no longer has any function. Instead, all query log files will be stored in the query history directory, next to the query results. [#1178](https://github.com/github/vscode-codeql/pull/1178)
## 1.5.11 - 10 February 2022

Просмотреть файл

@ -208,7 +208,8 @@
null
],
"default": null,
"description": "Path to a directory where the CodeQL extension should store query server logs. If empty, the extension stores logs in a temporary workspace folder and deletes the contents after each run."
"description": "Path to a directory where the CodeQL extension should store query server logs. If empty, the extension stores logs in a temporary workspace folder and deletes the contents after each run.",
"markdownDeprecationMessage": "This property is deprecated and no longer has any effect. All query logs are stored in the query history folder next to the query results."
},
"codeQL.runningQueries.quickEvalCodelens": {
"type": "boolean",

Просмотреть файл

@ -1111,9 +1111,6 @@ function getContextStoragePath(ctx: ExtensionContext) {
}
async function initializeLogging(ctx: ExtensionContext): Promise<void> {
const storagePath = getContextStoragePath(ctx);
await logger.setLogStoragePath(storagePath, false);
await ideServerLogger.setLogStoragePath(storagePath, false);
ctx.subscriptions.push(logger);
ctx.subscriptions.push(queryServerLogger);
ctx.subscriptions.push(ideServerLogger);

Просмотреть файл

@ -1,4 +1,4 @@
import { window as Window, OutputChannel, Progress, Disposable } from 'vscode';
import { window as Window, OutputChannel, Progress } from 'vscode';
import { DisposableObject } from './pure/disposable-object';
import * as fs from 'fs-extra';
import * as path from 'path';
@ -26,18 +26,6 @@ export interface Logger {
* @param location log to remove
*/
removeAdditionalLogLocation(location: string | undefined): void;
/**
* The base location where all side log files are stored.
*/
getBaseLocation(): string | undefined;
/**
* Sets the location where logs are stored.
* @param storagePath The path where logs are stored.
* @param isCustomLogDirectory Whether the logs are stored in a custom, user-specified directory.
*/
setLogStoragePath(storagePath: string, isCustomLogDirectory: boolean): Promise<void>;
}
export type ProgressReporter = Progress<{ message: string }>;
@ -46,27 +34,15 @@ export type ProgressReporter = Progress<{ message: string }>;
export class OutputChannelLogger extends DisposableObject implements Logger {
public readonly outputChannel: OutputChannel;
private readonly additionalLocations = new Map<string, AdditionalLogLocation>();
private additionalLogLocationPath: string | undefined;
isCustomLogDirectory: boolean;
constructor(private title: string) {
constructor(title: string) {
super();
this.outputChannel = Window.createOutputChannel(title);
this.push(this.outputChannel);
this.isCustomLogDirectory = false;
}
async setLogStoragePath(storagePath: string, isCustomLogDirectory: boolean): Promise<void> {
this.additionalLogLocationPath = path.join(storagePath, this.title);
this.isCustomLogDirectory = isCustomLogDirectory;
if (!this.isCustomLogDirectory) {
// clear out any old state from previous runs
await fs.remove(this.additionalLogLocationPath);
}
}
/**
* This function is asynchronous and will only resolve once the message is written
* to the side log (if required). It is not necessary to await the results of this
@ -84,8 +60,11 @@ export class OutputChannelLogger extends DisposableObject implements Logger {
this.outputChannel.append(message);
}
if (this.additionalLogLocationPath && options.additionalLogLocation) {
const logPath = path.join(this.additionalLogLocationPath, options.additionalLogLocation);
if (options.additionalLogLocation) {
if (!path.isAbsolute(options.additionalLogLocation)) {
throw new Error(`Additional Log Location must be an absolute path: ${options.additionalLogLocation}`);
}
const logPath = options.additionalLogLocation;
let additional = this.additionalLocations.get(logPath);
if (!additional) {
const msg = `| Log being saved to ${logPath} |`;
@ -93,9 +72,8 @@ export class OutputChannelLogger extends DisposableObject implements Logger {
this.outputChannel.appendLine(separator);
this.outputChannel.appendLine(msg);
this.outputChannel.appendLine(separator);
additional = new AdditionalLogLocation(logPath, !this.isCustomLogDirectory);
additional = new AdditionalLogLocation(logPath);
this.additionalLocations.set(logPath, additional);
this.track(additional);
}
await additional.log(message, options);
@ -115,26 +93,15 @@ export class OutputChannelLogger extends DisposableObject implements Logger {
}
removeAdditionalLogLocation(location: string | undefined): void {
if (this.additionalLogLocationPath && location) {
const logPath = location.startsWith(this.additionalLogLocationPath)
? location
: path.join(this.additionalLogLocationPath, location);
const additional = this.additionalLocations.get(logPath);
if (additional) {
this.disposeAndStopTracking(additional);
this.additionalLocations.delete(logPath);
}
if (location) {
this.additionalLocations.delete(location);
}
}
getBaseLocation() {
return this.additionalLogLocationPath;
}
}
class AdditionalLogLocation extends Disposable {
constructor(private location: string, private shouldDeleteLogs: boolean) {
super(() => { /**/ });
class AdditionalLogLocation {
constructor(private location: string) {
/**/
}
async log(message: string, options = {} as LogOptions): Promise<void> {
@ -147,12 +114,6 @@ class AdditionalLogLocation extends Disposable {
encoding: 'utf8'
});
}
async dispose(): Promise<void> {
if (this.shouldDeleteLogs) {
await fs.remove(this.location);
}
}
}
/** The global logger for the extension. */

Просмотреть файл

@ -9,8 +9,6 @@ import { Logger, ProgressReporter } from './logging';
import { completeQuery, EvaluationResult, progress, ProgressMessage, WithProgressId } from './pure/messages';
import * as messages from './pure/messages';
import { ProgressCallback, ProgressTask } from './commandRunner';
import * as fs from 'fs-extra';
import * as helpers from './helpers';
type ServerOpts = {
logger: Logger;
@ -68,7 +66,7 @@ export class QueryServerClient extends DisposableObject {
this.queryServerStartListeners.push(e);
}
public activeQueryName: string | undefined;
public activeQueryLogFIle: string | undefined;
constructor(
readonly config: QueryServerConfig,
@ -89,26 +87,6 @@ export class QueryServerClient extends DisposableObject {
this.evaluationResultCallbacks = {};
}
async initLogger() {
let storagePath = this.opts.contextStoragePath;
let isCustomLogDirectory = false;
if (this.config.customLogDirectory) {
try {
if (!(await fs.pathExists(this.config.customLogDirectory))) {
await fs.mkdir(this.config.customLogDirectory);
}
void this.logger.log(`Saving query server logs to user-specified directory: ${this.config.customLogDirectory}.`);
storagePath = this.config.customLogDirectory;
isCustomLogDirectory = true;
} catch (e) {
void helpers.showAndLogErrorMessage(`${this.config.customLogDirectory} is not a valid directory. Logs will be stored in a temporary workspace directory instead.`);
}
}
await this.logger.setLogStoragePath(storagePath, isCustomLogDirectory);
}
get logger(): Logger {
return this.opts.logger;
}
@ -150,7 +128,6 @@ export class QueryServerClient extends DisposableObject {
/** Starts a new query server process, sending progress messages to the given reporter. */
private async startQueryServerImpl(progressReporter: ProgressReporter): Promise<void> {
await this.initLogger();
const ramArgs = await this.cliServer.resolveRam(this.config.queryMemoryMb, progressReporter);
const args = ['--threads', this.config.numThreads.toString()].concat(ramArgs);
@ -175,7 +152,7 @@ export class QueryServerClient extends DisposableObject {
args.push('--evaluator-log');
args.push(`${this.opts.contextStoragePath}/structured-evaluator-log.json`);
// We hard-code the verbosity level to 5 and minify to false.
// We hard-code the verbosity level to 5 and minify to false.
// This will be the behavior of the per-query structured logging in the CLI after 2.8.3.
args.push('--evaluator-log-level');
args.push('5');
@ -197,7 +174,7 @@ export class QueryServerClient extends DisposableObject {
this.logger,
data => this.logger.log(data.toString(), {
trailingNewline: false,
additionalLogLocation: this.activeQueryName
additionalLogLocation: this.activeQueryLogFIle
}),
undefined, // no listener for stdout
progressReporter
@ -208,10 +185,6 @@ export class QueryServerClient extends DisposableObject {
if (!(res.runId in this.evaluationResultCallbacks)) {
void this.logger.log(`No callback associated with run id ${res.runId}, continuing without executing any callback`);
} else {
const baseLocation = this.logger.getBaseLocation();
if (baseLocation && this.activeQueryName) {
res.logFileLocation = path.join(baseLocation, this.activeQueryName);
}
this.evaluationResultCallbacks[res.runId](res);
}
return {};
@ -272,8 +245,11 @@ export class QueryServerClient extends DisposableObject {
*/
private updateActiveQuery(method: string, parameter: any): void {
if (method === messages.compileQuery.method) {
const queryPath = parameter?.queryToCheck?.queryPath || 'unknown';
this.activeQueryName = `query-${path.basename(queryPath)}-${this.nextProgress}.log`;
this.activeQueryLogFIle = findQueryLogFile(path.dirname(parameter.resultPath));
}
}
}
export function findQueryLogFile(resultPath: string): string {
return path.join(resultPath, 'query.log');
}

Просмотреть файл

@ -17,7 +17,14 @@ import { ErrorCodes, ResponseError } from 'vscode-languageclient';
import * as cli from './cli';
import * as config from './config';
import { DatabaseItem, DatabaseManager } from './databases';
import { createTimestampFile, getOnDiskWorkspaceFolders, showAndLogErrorMessage, tryGetQueryMetadata, upgradesTmpDir } from './helpers';
import {
createTimestampFile,
getOnDiskWorkspaceFolders,
showAndLogErrorMessage,
showAndLogInformationMessage,
tryGetQueryMetadata,
upgradesTmpDir
} from './helpers';
import { ProgressCallback, UserCancellationException } from './commandRunner';
import { DatabaseInfo, QueryMetadata } from './pure/interface-types';
import { logger } from './logging';
@ -83,6 +90,10 @@ export class QueryEvaluationInfo {
return path.join(this.querySaveDir, 'compiledQuery.qlo');
}
get logPath() {
return qsClient.findQueryLogFile(this.querySaveDir);
}
get resultsPaths() {
return {
resultsPath: path.join(this.querySaveDir, 'results.bqrs'),
@ -120,7 +131,12 @@ export class QueryEvaluationInfo {
let result: messages.EvaluationResult | null = null;
const callbackId = qs.registerCallback(res => { result = res; });
const callbackId = qs.registerCallback(res => {
result = {
...res,
logFileLocation: this.logPath
};
});
const availableMlModelUris: messages.MlModel[] = availableMlModels.map(model => ({ uri: Uri.file(model.path).toString(true) }));
@ -148,6 +164,11 @@ export class QueryEvaluationInfo {
};
try {
await qs.sendRequest(messages.runQueries, params, token, progress);
if (qs.config.customLogDirectory) {
void showAndLogInformationMessage(
`Custom log directory is not supported. Query logs saved to ${this.logPath}. The "codeQL.runningQueries.customLogDirectory" option is deprecated. Unset the option to stop seeing this message.`
);
}
} finally {
qs.unRegisterCallback(callbackId);
}
@ -192,7 +213,7 @@ export class QueryEvaluationInfo {
compiled = await qs.sendRequest(messages.compileQuery, params, token, progress);
} finally {
void qs.logger.log(' - - - COMPILATION DONE - - - ');
void qs.logger.log(' - - - COMPILATION DONE - - - ', { additionalLogLocation: this.logPath });
}
return (compiled?.messages || []).filter(msg => msg.severity === messages.Severity.ERROR);
}
@ -740,7 +761,10 @@ export async function compileAndRunQueryAgainstDatabase(
// so we include a general description of the problem,
// and direct the user to the output window for the detailed compilation messages.
// However we don't show quick eval errors there so we need to display them anyway.
void qs.logger.log(`Failed to compile query ${initialInfo.queryPath} against database scheme ${qlProgram.dbschemePath}:`);
void qs.logger.log(
`Failed to compile query ${initialInfo.queryPath} against database scheme ${qlProgram.dbschemePath}:`,
{ additionalLogLocation: query.logPath }
);
const formattedMessages: string[] = [];
@ -748,7 +772,7 @@ export async function compileAndRunQueryAgainstDatabase(
const message = error.message || '[no error message available]';
const formatted = `ERROR: ${message} (${error.position.fileName}:${error.position.line}:${error.position.column}:${error.position.endLine}:${error.position.endColumn})`;
formattedMessages.push(formatted);
void qs.logger.log(formatted);
void qs.logger.log(formatted, { additionalLogLocation: query.logPath });
}
if (initialInfo.isQuickEval && formattedMessages.length <= 2) {
// If there are more than 2 error messages, they will not be displayed well in a popup
@ -765,7 +789,10 @@ export async function compileAndRunQueryAgainstDatabase(
try {
await upgradeDir?.cleanup();
} catch (e) {
void qs.logger.log(`Could not clean up the upgrades dir. Reason: ${e.message || e}`);
void qs.logger.log(
`Could not clean up the upgrades dir. Reason: ${e.message || e}`,
{ additionalLogLocation: query.logPath }
);
}
}
}

Просмотреть файл

@ -12,7 +12,8 @@ const proxyquire = pq.noPreserveCache().noCallThru();
chai.use(sinonChai);
const expect = chai.expect;
describe('OutputChannelLogger tests', () => {
describe.only('OutputChannelLogger tests', function() {
this.timeout(999999);
let OutputChannelLogger;
const tempFolders: Record<string, tmp.DirResult> = {};
let logger: any;
@ -39,113 +40,24 @@ describe('OutputChannelLogger tests', () => {
expect(mockOutputChannel.appendLine).not.to.have.been.calledWith('yyy');
expect(mockOutputChannel.append).to.have.been.calledWith('yyy');
// additionalLogLocation ignored since not initialized
await logger.log('zzz', { additionalLogLocation: 'hucairz' });
await logger.log('zzz', createLogOptions('hucairz'));
// should not have created any side logs
expect(fs.readdirSync(tempFolders.globalStoragePath.name).length).to.equal(0);
expect(fs.readdirSync(tempFolders.storagePath.name).length).to.equal(0);
// should have created 1 side log
expect(fs.readdirSync(tempFolders.storagePath.name)).to.deep.equal(['hucairz']);
});
it('should create a side log in the workspace area', async () => {
await logger.setLogStoragePath(tempFolders.storagePath.name, false);
await logger.log('xxx', { additionalLogLocation: 'first' });
await logger.log('yyy', { additionalLogLocation: 'second' });
await logger.log('zzz', { additionalLogLocation: 'first', trailingNewline: false });
it('should create a side log', async () => {
await logger.log('xxx', createLogOptions('first'));
await logger.log('yyy', createLogOptions('second'));
await logger.log('zzz', createLogOptions('first', false));
await logger.log('aaa');
// expect 2 side logs
const testLoggerFolder = path.join(tempFolders.storagePath.name, 'test-logger');
expect(fs.readdirSync(testLoggerFolder).length).to.equal(2);
expect(fs.readdirSync(tempFolders.storagePath.name).length).to.equal(2);
// contents
expect(fs.readFileSync(path.join(testLoggerFolder, 'first'), 'utf8')).to.equal('xxx\nzzz');
expect(fs.readFileSync(path.join(testLoggerFolder, 'second'), 'utf8')).to.equal('yyy\n');
});
it('should delete side logs on dispose', async () => {
await logger.setLogStoragePath(tempFolders.storagePath.name, false);
await logger.log('xxx', { additionalLogLocation: 'first' });
await logger.log('yyy', { additionalLogLocation: 'second' });
const testLoggerFolder = path.join(tempFolders.storagePath.name, 'test-logger');
expect(fs.readdirSync(testLoggerFolder).length).to.equal(2);
await logger.dispose();
// need to wait for disposable-object to dispose
await waitABit();
expect(fs.readdirSync(testLoggerFolder).length).to.equal(0);
expect(mockOutputChannel.dispose).to.have.been.calledWith();
});
it('should not delete side logs on dispose in a custom directory', async () => {
await logger.setLogStoragePath(tempFolders.storagePath.name, true);
await logger.log('xxx', { additionalLogLocation: 'first' });
await logger.log('yyy', { additionalLogLocation: 'second' });
const testLoggerFolder = path.join(tempFolders.storagePath.name, 'test-logger');
expect(fs.readdirSync(testLoggerFolder).length).to.equal(2);
await logger.dispose();
// need to wait for disposable-object to dispose
await waitABit();
expect(fs.readdirSync(testLoggerFolder).length).to.equal(2);
expect(mockOutputChannel.dispose).to.have.been.calledWith();
});
it('should remove an additional log location', async () => {
await logger.setLogStoragePath(tempFolders.storagePath.name, false);
await logger.log('xxx', { additionalLogLocation: 'first' });
await logger.log('yyy', { additionalLogLocation: 'second' });
const testLoggerFolder = path.join(tempFolders.storagePath.name, 'test-logger');
expect(fs.readdirSync(testLoggerFolder).length).to.equal(2);
await logger.removeAdditionalLogLocation('first');
// need to wait for disposable-object to dispose
await waitABit();
expect(fs.readdirSync(testLoggerFolder).length).to.equal(1);
expect(fs.readFileSync(path.join(testLoggerFolder, 'second'), 'utf8')).to.equal('yyy\n');
});
it('should not remove an additional log location in a custom directory', async () => {
await logger.setLogStoragePath(tempFolders.storagePath.name, true);
await logger.log('xxx', { additionalLogLocation: 'first' });
await logger.log('yyy', { additionalLogLocation: 'second' });
const testLoggerFolder = path.join(tempFolders.storagePath.name, 'test-logger');
expect(fs.readdirSync(testLoggerFolder).length).to.equal(2);
await logger.removeAdditionalLogLocation('first');
// need to wait for disposable-object to dispose
await waitABit();
expect(fs.readdirSync(testLoggerFolder).length).to.equal(2);
expect(fs.readFileSync(path.join(testLoggerFolder, 'second'), 'utf8')).to.equal('yyy\n');
});
it('should delete an existing folder when setting the log storage path', async () => {
fs.createFileSync(path.join(tempFolders.storagePath.name, 'test-logger', 'xxx'));
await logger.setLogStoragePath(tempFolders.storagePath.name, false);
// should be empty dir
await waitABit();
const testLoggerFolder = path.join(tempFolders.storagePath.name, 'test-logger');
expect(fs.existsSync(testLoggerFolder)).to.be.false;
});
it('should not delete an existing folder when setting the log storage path for a custom directory', async () => {
fs.createFileSync(path.join(tempFolders.storagePath.name, 'test-logger', 'xxx'));
await logger.setLogStoragePath(tempFolders.storagePath.name, true);
// should not be empty dir
const testLoggerFolder = path.join(tempFolders.storagePath.name, 'test-logger');
expect(fs.readdirSync(testLoggerFolder).length).to.equal(1);
});
it('should show the output channel', () => {
logger.show(true);
expect(mockOutputChannel.show).to.have.been.calledWith(true);
expect(fs.readFileSync(path.join(tempFolders.storagePath.name, 'first'), 'utf8')).to.equal('xxx\nzzz');
expect(fs.readFileSync(path.join(tempFolders.storagePath.name, 'second'), 'utf8')).to.equal('yyy\n');
});
function createModule(): any {
@ -170,7 +82,10 @@ describe('OutputChannelLogger tests', () => {
});
}
function waitABit(ms = 50): Promise<void> {
return new Promise(resolve => setTimeout(resolve, ms));
function createLogOptions(additionalLogLocation: string, trailingNewline?: boolean) {
return {
additionalLogLocation: path.join(tempFolders.storagePath.name, additionalLogLocation),
trailingNewline,
};
}
});