summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
-rw-r--r--std/log/README.md10
-rw-r--r--std/log/handlers.ts59
-rw-r--r--std/log/handlers_test.ts132
3 files changed, 162 insertions, 39 deletions
diff --git a/std/log/README.md b/std/log/README.md
index 55b2b6cdb..4c69784f9 100644
--- a/std/log/README.md
+++ b/std/log/README.md
@@ -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
diff --git a/std/log/handlers.ts b/std/log/handlers.ts
index 3c8dd6896..b7a8c9cae 100644
--- a/std/log/handlers.ts
+++ b/std/log/handlers.ts
@@ -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);
}
}
diff --git a/std/log/handlers_test.ts b/std/log/handlers_test.ts
index 5275a5ca0..cb73fa56f 100644
--- a/std/log/handlers_test.ts
+++ b/std/log/handlers_test.ts
@@ -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);
+
+ 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));
- assertEquals(fileSzie, msgByteLength + 1);
- assertNotEquals(fileSzie, msgLength);
- assertNotEquals(fileSzie, msgLength + 1);
+ // 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);