foster/deno
0
0
Fork 0
mirror of https://github.com/denoland/deno.git synced 2025-03-03 09:31:22 -05:00
Code Issues Packages 1 Wiki Activity

feat(std/log): buffered file logging (#6014)

Browse source
This commit is contained in:
Chris Knight 2020-06-01 23:31:17 +01:00 • committed by GitHub
parent b693ca7f7f
commit c9aded05a6
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
3 changed files with 162 additions and 39 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

10
std/log/README.md
View file

@ -107,7 +107,10 @@ interface HandlerOptions {
#### `FileHandler`
This handler will output to a file using an optional mode (default is `a`, e.g.
append). The file will grow indefinitely. This logger takes `FileOptions`:
append). The file will grow indefinitely. It uses a buffer for writing to file
and will automatically flush every 30 seconds, though you can trigger this
yourself with `fileHandler.flush()`. Log messages with a log level greater than
error are immediately flushed. This logger takes `FileOptions`:
```typescript
interface FileHandlerOptions {
@ -148,6 +151,11 @@ backups to keep), `log.txt.1` would be renamed to `log.txt.2`, `log.txt` would
be renamed to `log.txt.1` and finally `log.txt` would be created from scratch
where the new log message would be written.
This handler uses a buffer for writing to file and will automatically flush
every 30 seconds, though you can trigger this yourself with
`fileHandler.flush()`. Log messages with a log level greater than error are
immediately flushed.
Options for this handler are:
```typescript

59
std/log/handlers.ts
View file

@ -7,6 +7,7 @@ import { getLevelByName, LevelName, LogLevels } from "./levels.ts";
import { LogRecord } from "./logger.ts";
import { red, yellow, blue, bold } from "../fmt/colors.ts";
import { existsSync, exists } from "../fs/exists.ts";
import { BufWriterSync } from "../io/bufio.ts";
const DEFAULT_FORMATTER = "{levelName} {msg}";
type FormatterFunction = (logRecord: LogRecord) => string;
@ -99,11 +100,14 @@ interface FileHandlerOptions extends HandlerOptions {
}
export class FileHandler extends WriterHandler {
protected _file!: File;
protected _file: File | undefined;
protected _buf!: BufWriterSync;
protected _filename: string;
protected _mode: LogMode;
protected _openOptions: OpenOptions;
#encoder = new TextEncoder();
protected _encoder = new TextEncoder();
#intervalId = -1;
#unloadCallback = (): Promise<void> => this.destroy();
constructor(levelName: LevelName, options: FileHandlerOptions) {
super(levelName, options);
@ -122,14 +126,39 @@ export class FileHandler extends WriterHandler {
async setup(): Promise<void> {
this._file = await open(this._filename, this._openOptions);
this._writer = this._file;
this._buf = new BufWriterSync(this._file);
addEventListener("unload", this.#unloadCallback);
// flush the buffer every 30 seconds
this.#intervalId = setInterval(() => this.flush(), 30 * 1000);
}
handle(logRecord: LogRecord): void {
super.handle(logRecord);
// Immediately flush if log level is higher than ERROR
if (logRecord.level > LogLevels.ERROR) {
this.flush();
}
}
log(msg: string): void {
Deno.writeAllSync(this._file, this.#encoder.encode(msg + "\n"));
this._buf.writeSync(this._encoder.encode(msg + "\n"));
}
flush(): void {
if (this._buf?.buffered() > 0) {
this._buf.flush();
}
}
destroy(): Promise<void> {
this._file.close();
this.flush();
this._file?.close();
this._file = undefined;
removeEventListener("unload", this.#unloadCallback);
clearInterval(this.#intervalId);
return Promise.resolve();
}
}
@ -143,7 +172,6 @@ export class RotatingFileHandler extends FileHandler {
#maxBytes: number;
#maxBackupCount: number;
#currentFileSize = 0;
#encoder = new TextEncoder();
constructor(levelName: LevelName, options: RotatingFileHandlerOptions) {
super(levelName, options);
@ -153,9 +181,11 @@ export class RotatingFileHandler extends FileHandler {
async setup(): Promise<void> {
if (this.#maxBytes < 1) {
this.destroy();
throw new Error("maxBytes cannot be less than 1");
}
if (this.#maxBackupCount < 1) {
this.destroy();
throw new Error("maxBackupCount cannot be less than 1");
}
await super.setup();
@ -172,7 +202,7 @@ export class RotatingFileHandler extends FileHandler {
// Throw if any backups also exist
for (let i = 1; i <= this.#maxBackupCount; i++) {
if (await exists(this._filename + "." + i)) {
Deno.close(this._file.rid);
this.destroy();
throw new Deno.errors.AlreadyExists(
"Backup log file " + this._filename + "." + i + " already exists"
);
@ -183,23 +213,21 @@ export class RotatingFileHandler extends FileHandler {
}
}
handle(logRecord: LogRecord): void {
if (this.level > logRecord.level) return;
log(msg: string): void {
const msgByteLength = this._encoder.encode(msg).byteLength + 1;
const msg = this.format(logRecord);
const msgByteLength = this.#encoder.encode(msg).byteLength + 1;
if (this.#currentFileSize + msgByteLength > this.#maxBytes) {
this.rotateLogFiles();
this.#currentFileSize = msgByteLength;
} else {
this.#currentFileSize += msgByteLength;
this.#currentFileSize = 0;
}
return this.log(msg);
this._buf.writeSync(this._encoder.encode(msg + "\n"));
this.#currentFileSize += msgByteLength;
}
rotateLogFiles(): void {
close(this._file.rid);
this._buf.flush();
close(this._file!.rid);
for (let i = this.#maxBackupCount - 1; i >= 0; i--) {
const source = this._filename + (i === 0 ? "" : "." + i);
@ -212,5 +240,6 @@ export class RotatingFileHandler extends FileHandler {
this._file = openSync(this._filename, this._openOptions);
this._writer = this._file;
this._buf = new BufWriterSync(this._file);
}
}

132
std/log/handlers_test.ts
View file

@ -120,14 +120,18 @@ test({
test({
name: "FileHandler with mode 'x' will throw if log file already exists",
async fn() {
const fileHandler = new FileHandler("WARNING", {
filename: LOG_FILE,
mode: "x",
});
Deno.writeFileSync(LOG_FILE, new TextEncoder().encode("hello world"));
await assertThrowsAsync(async () => {
Deno.writeFileSync(LOG_FILE, new TextEncoder().encode("hello world"));
const fileHandler = new FileHandler("WARNING", {
filename: LOG_FILE,
mode: "x",
});
await fileHandler.setup();
}, Deno.errors.AlreadyExists);
await fileHandler.destroy();
Deno.removeSync(LOG_FILE);
},
});
@ -172,30 +176,32 @@ test({
name:
"RotatingFileHandler with mode 'x' will throw if any log file already exists",
async fn() {
Deno.writeFileSync(
LOG_FILE + ".3",
new TextEncoder().encode("hello world")
);
const fileHandler = new RotatingFileHandler("WARNING", {
filename: LOG_FILE,
maxBytes: 50,
maxBackupCount: 3,
mode: "x",
});
await assertThrowsAsync(
async () => {
Deno.writeFileSync(
LOG_FILE + ".3",
new TextEncoder().encode("hello world")
);
const fileHandler = new RotatingFileHandler("WARNING", {
filename: LOG_FILE,
maxBytes: 50,
maxBackupCount: 3,
mode: "x",
});
await fileHandler.setup();
},
Deno.errors.AlreadyExists,
"Backup log file " + LOG_FILE + ".3 already exists"
);
fileHandler.destroy();
Deno.removeSync(LOG_FILE + ".3");
Deno.removeSync(LOG_FILE);
},
});
test({
name: "RotatingFileHandler with first rollover",
name: "RotatingFileHandler with first rollover, monitor step by step",
async fn() {
const fileHandler = new RotatingFileHandler("WARNING", {
filename: LOG_FILE,
@ -206,16 +212,43 @@ test({
await fileHandler.setup();
fileHandler.handle(new LogRecord("AAA", [], LogLevels.ERROR)); // 'ERROR AAA\n' = 10 bytes
fileHandler.flush();
assertEquals((await Deno.stat(LOG_FILE)).size, 10);
fileHandler.handle(new LogRecord("AAA", [], LogLevels.ERROR));
fileHandler.flush();
assertEquals((await Deno.stat(LOG_FILE)).size, 20);
fileHandler.handle(new LogRecord("AAA", [], LogLevels.ERROR));
fileHandler.flush();
// Rollover occurred. Log file now has 1 record, rollover file has the original 2
assertEquals((await Deno.stat(LOG_FILE)).size, 10);
assertEquals((await Deno.stat(LOG_FILE + ".1")).size, 20);
await fileHandler.destroy();
Deno.removeSync(LOG_FILE);
Deno.removeSync(LOG_FILE + ".1");
},
});
test({
name: "RotatingFileHandler with first rollover, check all at once",
async fn() {
const fileHandler = new RotatingFileHandler("WARNING", {
filename: LOG_FILE,
maxBytes: 25,
maxBackupCount: 3,
mode: "w",
});
await fileHandler.setup();
fileHandler.handle(new LogRecord("AAA", [], LogLevels.ERROR)); // 'ERROR AAA\n' = 10 bytes
fileHandler.handle(new LogRecord("AAA", [], LogLevels.ERROR));
fileHandler.handle(new LogRecord("AAA", [], LogLevels.ERROR));
await fileHandler.destroy();
assertEquals((await Deno.stat(LOG_FILE)).size, 10);
assertEquals((await Deno.stat(LOG_FILE + ".1")).size, 20);
Deno.removeSync(LOG_FILE);
Deno.removeSync(LOG_FILE + ".1");
},
@ -310,11 +343,29 @@ test({
});
test({
name: "RotatingFileHandler fileSize equal to bytelength of message + 1",
name: "Window unload flushes buffer",
async fn() {
const fileHandler = new FileHandler("WARNING", {
filename: LOG_FILE,
mode: "w",
});
await fileHandler.setup();
fileHandler.handle(new LogRecord("AAA", [], LogLevels.ERROR)); // 'ERROR AAA\n' = 10 bytes
assertEquals((await Deno.stat(LOG_FILE)).size, 0);
dispatchEvent(new Event("unload"));
assertEquals((await Deno.stat(LOG_FILE)).size, 10);
Deno.removeSync(LOG_FILE);
},
});
test({
name: "RotatingFileHandler: rotate on byte length, not msg length",
async fn() {
const fileHandler = new RotatingFileHandler("WARNING", {
filename: LOG_FILE,
maxBytes: 100,
maxBytes: 7,
maxBackupCount: 1,
mode: "w",
});
@ -323,12 +374,47 @@ test({
const msg = "。";
const msgLength = msg.length;
const msgByteLength = new TextEncoder().encode(msg).byteLength;
await fileHandler.log(msg);
const fileSzie = (await Deno.stat(LOG_FILE)).size;
assertNotEquals(msgLength, msgByteLength);
assertEquals(msgLength, 1);
assertEquals(msgByteLength, 3);
assertEquals(fileSzie, msgByteLength + 1);
assertNotEquals(fileSzie, msgLength);
assertNotEquals(fileSzie, msgLength + 1);
fileHandler.log(msg); // logs 4 bytes (including '\n')
fileHandler.log(msg); // max bytes is 7, but this would be 8. Rollover.
await fileHandler.destroy();
const fileSize1 = (await Deno.stat(LOG_FILE)).size;
const fileSize2 = (await Deno.stat(LOG_FILE + ".1")).size;
assertEquals(fileSize1, msgByteLength + 1);
assertEquals(fileSize2, msgByteLength + 1);
Deno.removeSync(LOG_FILE);
Deno.removeSync(LOG_FILE + ".1");
},
});
test({
name: "FileHandler: Critical logs trigger immediate flush",
async fn() {
const fileHandler = new FileHandler("WARNING", {
filename: LOG_FILE,
mode: "w",
});
await fileHandler.setup();
fileHandler.handle(new LogRecord("AAA", [], LogLevels.ERROR));
// ERROR won't trigger immediate flush
const fileSize = (await Deno.stat(LOG_FILE)).size;
assertEquals(fileSize, 0);
fileHandler.handle(new LogRecord("AAA", [], LogLevels.CRITICAL));
// CRITICAL will trigger immediate flush
const fileSize2 = (await Deno.stat(LOG_FILE)).size;
// ERROR record is 10 bytes, CRITICAL is 13 bytes
assertEquals(fileSize2, 23);
await fileHandler.destroy();
Deno.removeSync(LOG_FILE);