Make everything use active evals (#30)

* Add trace log level

* Use active eval to implement spdlog

* Split server/client active eval interfaces

Since all properties are *not* valid on both sides

* +200% fire resistance

* Implement exec using active evaluations

* Fully implement child process streams

* Watch impl, move child_process back to explicitly adding events

Automatically forwarding all events might be the right move, but wanna
think/discuss it a bit more because it didn't come out very cleanly.

* Would you like some args with that callback?

* Implement the rest of child_process using active evals

* Rampant memory leaks

Emit "kill" to active evaluations when client disconnects in order to
kill processes. Most likely won't be the final solution.

* Resolve some minor issues with output panel

* Implement node-pty with active evals

* Provide clearTimeout to vm sandbox

* Implement socket with active evals

* Extract some callback logic

Also remove some eval interfaces, need to re-think those.

* Implement net.Server and remainder of net.Socket using active evals

* Implement dispose for active evaluations

* Use trace for express requests

* Handle sending buffers through evaluation events

* Make event logging a bit more clear

* Fix some errors due to us not actually instantiating until connect/listen

* is this a commit message?

* We can just create the evaluator in the ctor

Not sure what I was thinking.

* memory leak for you, memory leak for everyone

* it's a ternary now

* Don't dispose automatically on close or error

The code may or may not be disposable at that point.

* Handle parsing buffers on the client side as well

* Remove unused protobuf

* Remove TypedValue

* Remove unused forkProvider and test

* Improve dispose pattern for active evals

* Socket calls close after error; no need to bind both

* Improve comment

* Comment is no longer wishy washy due to explicit boolean

* Simplify check for sendHandle and options

* Replace _require with __non_webpack_require__

Webpack will then replace this with `require` which we then provide to
the vm sandbox.

* Provide path.parse

* Prevent original-fs from loading

* Start with a pid of -1

vscode immediately checks the PID to see if the debug process launch
correctly, but of course we don't get the pid synchronously.

* Pass arguments to bootstrap-fork

* Fully implement streams

Was causing errors because internally the stream would set this.writing
to true and it would never become false, so subsequent messages would
never send.

* Fix serializing errors and streams emitting errors multiple times

* Was emitting close to data

* Fix missing path for spawned processes

* Move evaluation onDispose call

Now it's accurate and runs when the active evaluation has actually
disposed.

* Fix promisifying fs.exists

* Fix some active eval callback issues

* Patch existsSync in debug adapter
This commit is contained in:
Asher
2019-02-19 10:17:03 -06:00
committed by GitHub
parent 73762017c8
commit 4a80bcb42c
39 changed files with 1694 additions and 8731 deletions

View File

@@ -1,184 +1,67 @@
import { exec } from "child_process";
import { promisify } from "util";
import { appendFile, stat, readdir } from "fs";
/// <reference path="../../../../lib/vscode/src/typings/spdlog.d.ts" />
import { RotatingLogger as NodeRotatingLogger } from "spdlog";
import { logger, field } from "@coder/logger";
import { escapePath } from "@coder/protocol";
import { logger } from "@coder/logger";
import { client } from "@coder/ide/src/fill/client";
// TODO: It would be better to spawn an actual spdlog instance on the server and
// use that for the logging. Or maybe create an instance when the server starts,
// and just always use that one (make it part of the protocol).
declare var __non_webpack_require__: typeof require;
const ae = client.run((ae) => {
const spdlog = __non_webpack_require__("spdlog") as typeof import("spdlog");
const loggers = new Map<number, NodeRotatingLogger>();
ae.on("new", (id, name, filePath, fileSize, fileCount) => {
const logger = new spdlog.RotatingLogger(name, filePath, fileSize, fileCount);
loggers.set(id, logger);
});
ae.on("clearFormatters", (id) => loggers.get(id)!.clearFormatters());
ae.on("critical", (id, message) => loggers.get(id)!.critical(message));
ae.on("debug", (id, message) => loggers.get(id)!.debug(message));
ae.on("drop", (id) => loggers.get(id)!.drop());
ae.on("errorLog", (id, message) => loggers.get(id)!.error(message));
ae.on("flush", (id) => loggers.get(id)!.flush());
ae.on("info", (id, message) => loggers.get(id)!.info(message));
ae.on("setAsyncMode", (bufferSize, flushInterval) => spdlog.setAsyncMode(bufferSize, flushInterval));
ae.on("setLevel", (id, level) => loggers.get(id)!.setLevel(level));
ae.on("trace", (id, message) => loggers.get(id)!.trace(message));
ae.on("warn", (id, message) => loggers.get(id)!.warn(message));
const disposeCallbacks = <Array<() => void>>[];
return {
onDidDispose: (cb): number => disposeCallbacks.push(cb),
dispose: (): void => {
loggers.forEach((logger) => logger.flush());
loggers.clear();
disposeCallbacks.forEach((cb) => cb());
},
};
});
const spdLogger = logger.named("spdlog");
ae.on("close", () => spdLogger.error("session closed prematurely"));
ae.on("error", (error) => spdLogger.error(error.message));
let id = 0;
export class RotatingLogger implements NodeRotatingLogger {
private format = true;
private buffer = "";
private flushPromise: Promise<void> | undefined;
private name: string;
private logDirectory: string;
private escapedLogDirectory: string;
private fullFilePath: string;
private fileName: string;
private fileExt: string | undefined;
private escapedFilePath: string;
private filesize: number;
private filecount: number;
private readonly id = id++;
public constructor(name: string, filePath: string, filesize: number, filecount: number) {
this.name = name;
this.filesize = filesize;
this.filecount = filecount;
this.fullFilePath = filePath;
const slashIndex = filePath.lastIndexOf("/");
const dotIndex = filePath.lastIndexOf(".");
this.logDirectory = slashIndex !== -1 ? filePath.substring(0, slashIndex) : "/";
this.fileName = filePath.substring(slashIndex + 1, dotIndex !== -1 ? dotIndex : undefined);
this.fileExt = dotIndex !== -1 ? filePath.substring(dotIndex + 1) : undefined;
this.escapedLogDirectory = escapePath(this.logDirectory);
this.escapedFilePath = escapePath(filePath);
this.flushPromise = new Promise((resolve): void => {
exec(`mkdir -p ${this.escapedLogDirectory}; touch ${this.escapedFilePath}`, async (error) => {
if (!error) {
try {
await this.doFlush();
} catch (e) {
error = e;
}
}
if (error) {
logger.error(error.message, field("error", error));
}
this.flushPromise = undefined;
resolve();
});
});
public constructor(name: string, filePath: string, fileSize: number, fileCount: number) {
ae.emit("new", this.id, name, filePath, fileSize, fileCount);
}
public trace(message: string): void {
this.write("trace", message);
}
public debug(message: string): void {
this.write("debug", message);
}
public info(message: string): void {
this.write("info", message);
}
public warn(message: string): void {
this.write("warn", message);
}
public error(message: string): void {
this.write("error", message);
}
public critical(message: string): void {
this.write("critical", message);
}
public setLevel(): void {
// Should output everything.
}
public clearFormatters(): void {
this.format = false;
}
/**
* Flushes the buffer. Only one process runs at a time to prevent race
* conditions.
*/
public flush(): Promise<void> {
if (!this.flushPromise) {
this.flushPromise = this.doFlush().then(() => {
this.flushPromise = undefined;
}).catch((error) => {
this.flushPromise = undefined;
logger.error(error.message, field("error", error));
});
}
return this.flushPromise;
}
public drop(): void {
this.buffer = "";
}
private pad(num: number, length: number = 2, prefix: string = "0"): string {
const str = num.toString();
return (length > str.length ? prefix.repeat(length - str.length) : "") + str;
}
private write(severity: string, message: string): void {
if (this.format) {
const date = new Date();
const dateStr = `${date.getFullYear()}-${this.pad(date.getMonth() + 1)}-${this.pad(date.getDate())}`
+ ` ${this.pad(date.getHours())}:${this.pad(date.getMinutes())}:${this.pad(date.getSeconds())}.${this.pad(date.getMilliseconds(), 3)}`;
this.buffer += `[${dateStr}] [${this.name}] [${severity}] `;
}
this.buffer += message;
if (this.format) {
this.buffer += "\n";
}
this.flush();
}
private async rotate(): Promise<void> {
const stats = await promisify(stat)(this.fullFilePath);
if (stats.size < this.filesize) {
return;
}
const reExt = typeof this.fileExt !== "undefined" ? `\\.${this.fileExt}` : "";
const re = new RegExp(`^${this.fileName}(?:\\.(\\d+))?${reExt}$`);
const orderedFiles: string[] = [];
(await promisify(readdir)(this.logDirectory)).forEach((file) => {
const match = re.exec(file);
if (match) {
orderedFiles[typeof match[1] !== "undefined" ? parseInt(match[1], 10) : 0] = file;
}
});
// Rename in reverse so we don't overwrite before renaming something.
let count = 0;
const command = orderedFiles.map((file) => {
const fileExt = typeof this.fileExt !== "undefined" ? `.${this.fileExt}` : "";
const newFile = `${this.logDirectory}/${this.fileName}.${++count}${fileExt}`;
return count >= this.filecount
? `rm ${escapePath(this.logDirectory + "/" + file)}`
: `mv ${escapePath(this.logDirectory + "/" + file)} ${escapePath(newFile)}`;
}).reverse().concat([
`touch ${escapePath(this.fullFilePath)}`,
]).join(";");
await promisify(exec)(command);
}
/**
* Flushes the entire buffer, including anything added in the meantime, and
* rotates the log if necessary.
*/
private async doFlush(): Promise<void> {
const writeBuffer = async (): Promise<void> => {
const toWrite = this.buffer;
this.buffer = "";
await promisify(appendFile)(this.fullFilePath, toWrite);
};
while (this.buffer.length > 0) {
await writeBuffer();
await this.rotate();
}
}
public trace(message: string): void { ae.emit("trace", this.id, message); }
public debug(message: string): void { ae.emit("debug", this.id, message); }
public info(message: string): void { ae.emit("info", this.id, message); }
public warn(message: string): void { ae.emit("warn", this.id, message); }
public error(message: string): void { ae.emit("errorLog", this.id, message); }
public critical(message: string): void { ae.emit("critical", this.id, message); }
public setLevel(level: number): void { ae.emit("setLevel", this.id, level); }
public clearFormatters(): void { ae.emit("clearFormatters", this.id); }
public flush(): void { ae.emit("flush", this.id); }
public drop(): void { ae.emit("drop", this.id); }
}
export const setAsyncMode = (): void => {
// Nothing to do.
export const setAsyncMode = (bufferSize: number, flushInterval: number): void => {
ae.emit("setAsyncMode", bufferSize, flushInterval);
};