Merge pull request #523 from devchat-ai/optimize_logging_output

Improve code readability by updating logger.trace calls
This commit is contained in:
boob.yang 2024-05-18 15:14:52 +08:00 committed by GitHub
commit 293bf32857
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
19 changed files with 117 additions and 122 deletions

View File

@ -20,12 +20,12 @@ export const customCommandContext: ChatContext = {
const tempDir = await createTempSubdirectory('devchat/context'); const tempDir = await createTempSubdirectory('devchat/context');
const diffFile = path.join(tempDir, 'custom.txt'); const diffFile = path.join(tempDir, 'custom.txt');
logger.channel()?.info(`Your custom command is: ${customCommand}`); logger.channel()?.trace(`Your custom command is: ${customCommand}`);
const result = await runCommandStringAndWriteOutput(customCommand, diffFile); const result = await runCommandStringAndWriteOutput(customCommand, diffFile);
logger.channel()?.info(` exit code:`, result.exitCode); logger.channel()?.trace(` exit code:`, result.exitCode);
logger.channel()?.debug(` stdout:`, result.stdout); logger.channel()?.trace(` stdout:`, result.stdout);
logger.channel()?.debug(` stderr:`, result.stderr); logger.channel()?.trace(` stderr:`, result.stderr);
return [`[context|${diffFile}]`]; return [`[context|${diffFile}]`];
} }
return []; return [];

View File

@ -54,7 +54,7 @@ export async function getParserForFile(filepath: string) {
parserCache.set(extension, parser); parserCache.set(extension, parser);
return parser; return parser;
} catch (e) { } catch (e) {
logger.channel()?.error("Unable to load language for file", filepath, e); logger.channel()?.warn("Unable to load language for file", filepath, e);
return undefined; return undefined;
} }
} }
@ -89,7 +89,7 @@ export async function getLanguageForFile(
langCache.set(extension, language); langCache.set(extension, language);
return language; return language;
} catch (e) { } catch (e) {
logger.channel()?.error("Unable to load language for file:", filepath, e); logger.channel()?.warn("Unable to load language for file:", filepath, e);
return undefined; return undefined;
} }
} }

View File

@ -83,14 +83,14 @@ export async function indexDir(dir: string) {
} }
try { try {
logger.channel()?.info(`Indexing ${file}`); logger.channel()?.trace(`Indexing ${file}`);
const newFileBlockInfo = await createFileBlockInfo(file); const newFileBlockInfo = await createFileBlockInfo(file);
if (newFileBlockInfo) { if (newFileBlockInfo) {
await indexStore!.add(newFileBlockInfo); await indexStore!.add(newFileBlockInfo);
indexUpdated = true; indexUpdated = true;
} }
} catch (err) { } catch (err) {
logger.channel()?.error(`${err}`); logger.channel()?.warn(`${err}`);
} }
} }
@ -98,7 +98,7 @@ export async function indexDir(dir: string) {
try { try {
await indexStore!.save(); await indexStore!.save();
} catch (err) { } catch (err) {
logger.channel()?.error(`${err}`); logger.channel()?.warn(`${err}`);
} }
} }
}; };

View File

@ -30,5 +30,5 @@ export async function outputAst(
// output ast // output ast
const treeText = "\n" + printTree(ast.rootNode, 0); const treeText = "\n" + printTree(ast.rootNode, 0);
logger.channel()?.info(treeText); logger.channel()?.trace(treeText);
} }

View File

@ -83,9 +83,7 @@ export class InlineCompletionProvider implements vscode.InlineCompletionItemProv
try { try {
const response = await fetch(apiUrl, requestOptions); const response = await fetch(apiUrl, requestOptions);
if (!response.ok) { if (!response.ok) {
if (this.devchatConfig.get("complete_debug")) { logger.channel()?.info("log event to server failed:", response.status);
logger.channel()?.info("log event to server failed:", response.status);
}
} }
} catch (error) { } catch (error) {
console.error('Error posting event to the server:', error); console.error('Error posting event to the server:', error);
@ -130,24 +128,18 @@ export class InlineCompletionProvider implements vscode.InlineCompletionItemProv
const fileContent = document.getText(); const fileContent = document.getText();
const posOffset = document.offsetAt(position); const posOffset = document.offsetAt(position);
if (completeDebug) { logger.channel()?.debug(`cur position: ${position.line}: ${position.character}`);
logger.channel()?.info(`cur position: ${position.line}: ${position.character}`);
}
const prompt = await createPrompt(fsPath, fileContent, position.line, position.character, posOffset, this.recentEditors.getEdits()); const prompt = await createPrompt(fsPath, fileContent, position.line, position.character, posOffset, this.recentEditors.getEdits());
if (!prompt) { if (!prompt) {
return undefined; return undefined;
} }
if (completeDebug) { logger.channel()?.trace("prompt:", prompt);
logger.channel()?.info("prompt:", prompt);
}
// check cache // check cache
const result = await this.cache.get(prompt); const result = await this.cache.get(prompt);
if (result) { if (result) {
if (completeDebug) { logger.channel()?.debug(`cache hited:\n${result.code}`);
logger.channel()?.info(`cache hited:\n${result.code}`);
}
return result; return result;
} }
@ -240,9 +232,7 @@ export class InlineCompletionProvider implements vscode.InlineCompletionItemProv
// TODO // TODO
// 代码补全建议是否已经被用户看到,这个需要更加准确的方式来识别。 // 代码补全建议是否已经被用户看到,这个需要更加准确的方式来识别。
if (completeDebug) { logger.channel()?.trace("code complete show.");
logger.channel()?.info("code complete show.");
}
this.logEventToServer( this.logEventToServer(
{ {
completion_id: response.id, completion_id: response.id,
@ -253,16 +243,12 @@ export class InlineCompletionProvider implements vscode.InlineCompletionItemProv
// log to server // log to server
const logRejectionTimeout: NodeJS.Timeout = setTimeout(() => { const logRejectionTimeout: NodeJS.Timeout = setTimeout(() => {
if (completeDebug) { logger.channel()?.trace("code complete not accept.");
logger.channel()?.info("code complete not accept.");
}
}, 10_000); }, 10_000);
// 代码补全回调处理 // 代码补全回调处理
const callback = () => { const callback = () => {
if (completeDebug) { logger.channel()?.trace("accept:", response!.id);
logger.channel()?.info("accept:", response!.id);
}
// delete cache // delete cache
this.cache.delete(response!.prompt); this.cache.delete(response!.prompt);
// delete timer // delete timer

View File

@ -88,7 +88,7 @@ export async function * nvidiaStarcoderComplete(prompt: string) : AsyncGenerator
// data: {"id": "cmpl-1713846153", "created": 1713846160.366049, "object": "completion.chunk", "model": "ollama/starcoder2:7b", "choices": [{"index": 0, "finish_reason": "stop", "text": ""}], "usage": {"prompt_tokens": 413, "completion_tokens": 16}} // data: {"id": "cmpl-1713846153", "created": 1713846160.366049, "object": "completion.chunk", "model": "ollama/starcoder2:7b", "choices": [{"index": 0, "finish_reason": "stop", "text": ""}], "usage": {"prompt_tokens": 413, "completion_tokens": 16}}
if (!chunkText.startsWith("data:")) { if (!chunkText.startsWith("data:")) {
// log unexpected data // log unexpected data
logger.channel()?.info("Unexpected data: " + chunkText); logger.channel()?.warn("Unexpected data: " + chunkText);
return; return;
} }
@ -105,7 +105,7 @@ export async function * nvidiaStarcoderComplete(prompt: string) : AsyncGenerator
}; };
} catch (e: any) { } catch (e: any) {
logger.channel()?.info("receve:", chunkText); logger.channel()?.info("receve:", chunkText);
logger.channel()?.error("JSON Parsing Error:", e.message); logger.channel()?.warn("JSON Parsing Error:", e.message);
} }
} }
} }
@ -234,7 +234,7 @@ export async function * devchatComplete(prompt: string) : AsyncGenerator<CodeCom
// data: {"id": "cmpl-1713846153", "created": 1713846160.366049, "object": "completion.chunk", "model": "ollama/starcoder2:7b", "choices": [{"index": 0, "finish_reason": "stop", "text": ""}], "usage": {"prompt_tokens": 413, "completion_tokens": 16}} // data: {"id": "cmpl-1713846153", "created": 1713846160.366049, "object": "completion.chunk", "model": "ollama/starcoder2:7b", "choices": [{"index": 0, "finish_reason": "stop", "text": ""}], "usage": {"prompt_tokens": 413, "completion_tokens": 16}}
if (!chunkText.startsWith("data:")) { if (!chunkText.startsWith("data:")) {
// log unexpected data // log unexpected data
logger.channel()?.info("Unexpected data: " + chunkText); logger.channel()?.warn("Unexpected data: " + chunkText);
return; return;
} }
@ -251,7 +251,7 @@ export async function * devchatComplete(prompt: string) : AsyncGenerator<CodeCom
}; };
} catch (e: any) { } catch (e: any) {
logger.channel()?.info("receve:", chunkText); logger.channel()?.info("receve:", chunkText);
logger.channel()?.error("JSON Parsing Error:", e.message); logger.channel()?.warn("JSON Parsing Error:", e.message);
} }
} }
} }

View File

@ -668,7 +668,7 @@ export async function createPrompt(filePath: string, fileContent: string, line:
} }
} }
logger.channel()?.info("Complete token:", tokenCount); logger.channel()?.debug("Complete token:", tokenCount);
let prompt = ""; let prompt = "";
let completeModel: string = DevChatConfig.getInstance().get("complete_model"); let completeModel: string = DevChatConfig.getInstance().get("complete_model");

View File

@ -133,7 +133,7 @@ export async function embeddingBlocks(file: string): Promise< {vector: number[],
vector[symbolMap.get(symbol)! - 1] = 1; vector[symbolMap.get(symbol)! - 1] = 1;
} else { } else {
if (symbolMap.size >= 5000) { if (symbolMap.size >= 5000) {
logger.channel()?.error(`symbolMap size is too large, symbol: ${symbol}`); logger.channel()?.warn(`symbolMap size is too large, symbol: ${symbol}`);
continue; continue;
} }
symbolMapUpdated = true; symbolMapUpdated = true;

View File

@ -171,7 +171,6 @@ async function activate(context: vscode.ExtensionContext) {
registerQuickFixCommand(context); registerQuickFixCommand(context);
startRpcServer(); startRpcServer();
logger.channel()?.info(`registerHandleUri:`);
registerHandleUri(context); registerHandleUri(context);
registerQuickFixProvider(); registerQuickFixProvider();

View File

@ -22,11 +22,11 @@ export class MessageHandler {
const handler = this.handlers[message.command]; const handler = this.handlers[message.command];
if (handler) { if (handler) {
logger.channel()?.info(`Handling the command "${message.command}"`); logger.channel()?.trace(`Handling the command "${message.command}"`);
await handler(message, panel); await handler(message, panel);
logger.channel()?.info(`Handling the command "${message.command}" done`); logger.channel()?.trace(`Handling the command "${message.command}" done`);
} else { } else {
logger.channel()?.error(`No handler found for the command "${message.command}"`); logger.channel()?.warn(`No handler found for the command "${message.command}"`);
logger.channel()?.show(); logger.channel()?.show();
} }
@ -34,9 +34,8 @@ export class MessageHandler {
MessageHandler.sendMessage(panel, { command: 'receiveMessage', text: 'finish', hash: '', user: '', date: 1, isError: false }); MessageHandler.sendMessage(panel, { command: 'receiveMessage', text: 'finish', hash: '', user: '', date: 1, isError: false });
} }
} catch (e) { } catch (e) {
logger.channel()?.error(`Error handling the message: "${JSON.stringify(message)}"`); logger.channel()?.warn(`Error handling the message: "${JSON.stringify(message)}"`);
logger.channel()?.show(); logger.channel()?.show();
} }
} }
@ -57,7 +56,7 @@ export class MessageHandler {
public static sendMessage(panel: vscode.WebviewPanel|vscode.WebviewView, message : any, log: boolean = true): void { public static sendMessage(panel: vscode.WebviewPanel|vscode.WebviewView, message : any, log: boolean = true): void {
if (log) { if (log) {
logger.channel()?.info(`Sending message: "${JSON.stringify(message)}"`); logger.channel()?.trace(`Message to GUI: "${JSON.stringify(message)}"`);
} }
panel.webview.postMessage(message); panel.webview.postMessage(message);

View File

@ -166,7 +166,7 @@ export async function sendMessageBase(message: any, handlePartialData: (data: {
// parse context and others from message // parse context and others from message
const [parsedMessage, chatOptions] = await parseMessageAndSetOptions(message); const [parsedMessage, chatOptions] = await parseMessageAndSetOptions(message);
logger.channel()?.info(`parent hash: ${chatOptions.parent}`); logger.channel()?.trace(`parent hash: ${chatOptions.parent}`);
// call devchat chat // call devchat chat
const chatResponse = await devChat.chat( const chatResponse = await devChat.chat(

View File

@ -91,7 +91,7 @@ let server: http.Server | null = null;
export async function startRpcServer() { export async function startRpcServer() {
server = http.createServer((req, res) => { server = http.createServer((req, res) => {
const parsedUrl = new URL(req.url!, `http://${req.headers.host}`); const parsedUrl = new URL(req.url!, `http://${req.headers.host}`);
logger.channel()?.info(`request: ${parsedUrl}`); logger.channel()?.trace(`request: ${parsedUrl}`);
if (parsedUrl.pathname === "/favicon.ico") { if (parsedUrl.pathname === "/favicon.ico") {
res.writeHead(204); res.writeHead(204);
res.end(); res.end();
@ -166,7 +166,7 @@ export async function startRpcServer() {
responseResult["result"] = res; responseResult["result"] = res;
} }
} catch (error) { } catch (error) {
logger.channel()?.warn(`Error: ${error}`); logger.channel()?.warn(`warning: ${error}`);
responseResult["result"] = res; responseResult["result"] = res;
} }

View File

@ -249,7 +249,7 @@ class FunctionTestCodeLensProvider implements vscode.CodeLensProvider {
// log info find how many functionDefinitions, innerFunctionDefinitions, lenses // log info find how many functionDefinitions, innerFunctionDefinitions, lenses
logger logger
.channel() .channel()
?.info( ?.trace(
`found ${functionDefinitions.length} functions, ${innerFunctionDefinitions.length} inner functions, ${lenses.length} registered codeLenses in document: ${document.fileName}` `found ${functionDefinitions.length} functions, ${innerFunctionDefinitions.length} inner functions, ${lenses.length} registered codeLenses in document: ${document.fileName}`
); );
return lenses; return lenses;

View File

@ -498,7 +498,7 @@ class DevChat {
logger.channel()?.warn(`${stderr}`); logger.channel()?.warn(`${stderr}`);
} }
logger.channel()?.info(`${stdout}`); logger.channel()?.trace(`${stdout}`);
return stdout; return stdout;
} catch (error: any) { } catch (error: any) {
logger.channel()?.error(`Error: ${error.message}`); logger.channel()?.error(`Error: ${error.message}`);

View File

@ -60,85 +60,91 @@ export class CommandRun {
this.childProcess = null; this.childProcess = null;
} }
public async spawnAsync(command: string, args: string[], options: object, onData: ((data: string) => void) | undefined, onError: ((data: string) => void) | undefined, onOutputFile: ((command: string, stdout: string, stderr: string) => string) | undefined, outputFile: string | undefined): Promise<CommandResult> { public async spawnAsync(command: string, args: string[], options: object, onData: ((data: string) => void) | undefined, onError: ((data: string) => void) | undefined, onOutputFile: ((command: string, stdout: string, stderr: string) => string) | undefined, outputFile: string | undefined): Promise<CommandResult> {
return new Promise((resolve, reject) => { return new Promise((resolve, reject) => {
logger.channel()?.info(`Running command: ${command} ${args.join(' ')}`); logger.channel()?.debug(`Running command: ${command} ${args.join(' ')}`);
this._input = ""; this._input = "";
const argsNew: string[] = args.map((arg) => { const argsNew: string[] = args.map((arg) => {
if (arg.trim()[0] === '$') { if (arg.trim()[0] === '$') {
// get rest string except '$' const restStr = arg.trim().slice(1);
const restStr = arg.trim().slice(1); if (process.env[restStr]) {
if (process.env[restStr]) { return process.env[restStr]!;
return process.env[restStr]!; } else {
} else { return arg;
return arg; }
} } else {
} else { return arg;
return arg; }
} });
});
this.childProcess = spawn(command, argsNew, options); this.childProcess = spawn(command, argsNew, options);
let stdout = ''; let stdout = '';
let stderr = ''; let stderr = '';
this.childProcess.stdout.on('data', (data: { toString: () => any; }) => { // Record process start time
const dataStr = this._input + data.toString(); const startTime = process.hrtime();
this._input = "";
if (onData) {
onData(dataStr);
}
stdout += dataStr;
});
this.childProcess.stderr.on('data', (data: string) => { this.childProcess.stdout.on('data', (data: { toString: () => any; }) => {
const dataStr = data.toString(); const dataStr = this._input + data.toString();
if (onError) { this._input = "";
onError(dataStr); if (onData) {
} onData(dataStr);
stderr += dataStr; }
}); stdout += dataStr;
});
this.childProcess.on('close', (code: number) => { this.childProcess.stderr.on('data', (data: string) => {
let outputData = stdout; const dataStr = data.toString();
if (onOutputFile) { if (onError) {
outputData = onOutputFile(command + " " + args.join(" "), stdout, stderr); onError(dataStr);
} }
stderr += dataStr;
});
if (outputFile) { this.childProcess.on('close', (code: number) => {
fs.writeFileSync(outputFile, outputData); let outputData = stdout;
} if (onOutputFile) {
outputData = onOutputFile(command + " " + args.join(" "), stdout, stderr);
}
if (stderr && !onError) { if (outputFile) {
logger.channel()?.error(stderr); fs.writeFileSync(outputFile, outputData);
logger.channel()?.show(); }
}
this.childProcess = null; if (stderr && !onError) {
if (code === 0) { logger.channel()?.error(stderr);
resolve({ exitCode: code, stdout, stderr }); logger.channel()?.show();
} else { }
resolve({ exitCode: code, stdout, stderr });
}
});
// Add error event listener to handle command not found exception this.childProcess = null;
this.childProcess.on('error', (error: any) => { if (code === 0) {
this.childProcess = null; resolve({ exitCode: code, stdout, stderr });
let errorMessage = error.message; } else {
if (error.code === 'ENOENT') { resolve({ exitCode: code, stdout, stderr });
errorMessage = `Command not found: ${command}`; }
logger.channel()?.error(`Command "${command}" not found`);
logger.channel()?.show(); // Record process end time and calculate duration
} else { const endTime = process.hrtime(startTime);
logger.channel()?.error(`Error: ${error.message}`); const duration = endTime[0] + endTime[1] / 1e9;
logger.channel()?.show(); logger.channel()?.debug(`Process took ${duration} seconds`);
} });
resolve({ exitCode: error.code, stdout: "", stderr: errorMessage });
}); this.childProcess.on('error', (error: any) => {
}); this.childProcess = null;
}; let errorMessage = error.message;
if (error.code === 'ENOENT') {
errorMessage = `Command not found: ${command}`;
logger.channel()?.error(`Command "${command}" not found`);
logger.channel()?.show();
} else {
logger.channel()?.error(`Error: ${error.message}`);
logger.channel()?.show();
}
resolve({ exitCode: error.code, stdout: "", stderr: errorMessage });
});
});
};
public write(input: string) { public write(input: string) {
if (this.childProcess) { if (this.childProcess) {

View File

@ -4,6 +4,7 @@ export interface LogChannel {
warn(message: string, ...args: any[]): void; warn(message: string, ...args: any[]): void;
error(message: string | Error, ...args: any[]): void; error(message: string | Error, ...args: any[]): void;
debug(message: string, ...args: any[]): void; debug(message: string, ...args: any[]): void;
trace(message: string, ...args: any[]): void;
show(): void; show(): void;
} }

View File

@ -33,6 +33,10 @@ export class LoggerChannelVscode implements LogChannel {
this._channel.debug(message, ...args); this._channel.debug(message, ...args);
} }
trace(message: string, ...args: any[]): void {
this._channel.trace(message, ...args);
}
show(): void { show(): void {
this._channel.show(); this._channel.show();
} }

View File

@ -11,7 +11,7 @@ import path from 'path';
function getDownloadFileName(): string { function getDownloadFileName(): string {
const platform = os.platform(); const platform = os.platform();
const arch = os.arch(); const arch = os.arch();
logger.channel()?.info(`Platform: ${platform}, Arch: ${arch}`); logger.channel()?.debug(`Platform: ${platform}, Arch: ${arch}`);
if (platform === "win32") { if (platform === "win32") {
if (arch === "x64") { if (arch === "x64") {
@ -55,7 +55,7 @@ import path from 'path';
export function getMicromambaUrl(): string { export function getMicromambaUrl(): string {
const platform = os.platform(); const platform = os.platform();
const arch = os.arch(); const arch = os.arch();
logger.channel()?.info(`Platform: ${platform}, Arch: ${arch}`); logger.channel()?.debug(`Platform: ${platform}, Arch: ${arch}`);
let micromambaUrl = ''; let micromambaUrl = '';
if (platform === "win32") { if (platform === "win32") {

2
tools

@ -1 +1 @@
Subproject commit 501b7ff4aee1656e543f23a3e5f88210f1eaaa7c Subproject commit 66da07cc2536a05ba3641122dfe62f1fa009cfb9