From 4a49b6c5a4155329052b2511cf70d7f8c7284706 Mon Sep 17 00:00:00 2001 From: Vatsal Goel <144617902+VatsalGoel3@users.noreply.github.com> Date: Wed, 12 Feb 2025 02:26:37 -0700 Subject: [PATCH 1/5] feat(logger): add log buffering module (SizedItem, SizedSet, CircularMap) --- packages/logger/src/logBuffer.ts | 92 ++++++++++++++++++++++++++++++++ 1 file changed, 92 insertions(+) create mode 100644 packages/logger/src/logBuffer.ts diff --git a/packages/logger/src/logBuffer.ts b/packages/logger/src/logBuffer.ts new file mode 100644 index 0000000000..a40de773a5 --- /dev/null +++ b/packages/logger/src/logBuffer.ts @@ -0,0 +1,92 @@ +import { buffer } from 'node:stream/consumers'; +import { it } from 'node:test'; + +export class SizedItem { + public value: V; + public logLevel: number; + public byteSize: number; + + constructor(value: V, logLevel: number) { + this.value = value; + this.logLevel = logLevel; + this.byteSize = Buffer.byteLength(JSON.stringify(value)); + } +} + +export class SizedSet extends Set> { + public currentBytesSize = 0; + + add(item: SizedItem): this { + this.currentBytesSize += item.byteSize; + super.add(item); + return this; + } + + delete(item: SizedItem): boolean { + const wasDeleted = super.delete(item); + if (wasDeleted) { + this.currentBytesSize -= item.byteSize; + } + return wasDeleted; + } + + clear(): void { + super.clear(); + this.currentBytesSize = 0; + } + + shift(): SizedItem | undefined { + const firstElement = this.values().next().value; + if (firstElement) { + this.delete(firstElement); + } + return firstElement; + } +} + +export class CircularMap extends Map> { + #maxBytesSize: number; + #onBufferOverflow?: () => void; + + constructor({ + maxBytesSize, + onBufferOverflow, + }: { + maxBytesSize: number; + onBufferOverflow?: () => void; + }) { + super(); + this.#maxBytesSize = maxBytesSize; + this.#onBufferOverflow = onBufferOverflow; + } + + setItem(key: string, value: V, logLevel: number): this { + const item = new SizedItem(value, logLevel); + + if (item.byteSize > this.#maxBytesSize) { + throw new Error('Item too big'); + } + + const buffer = this.get(key) || new SizedSet(); + + if (buffer.currentBytesSize + item.byteSize >= this.#maxBytesSize) { + this.#deleteFromBufferUntilSizeIsLessThanMax(buffer, item); + if (this.#onBufferOverflow) { + this.#onBufferOverflow(); + } + } + + buffer.add(item); + super.set(key, buffer); + return this; + } + + #deleteFromBufferUntilSizeIsLessThanMax = ( + buffer: SizedSet, + item: SizedItem + ) => { + while (buffer.currentBytesSize + item.byteSize >= this.#maxBytesSize) { + buffer.shift(); + } + }; +} From ac9b16ac11ee68f892338aa95520975a7b3bb4d1 Mon Sep 17 00:00:00 2001 From: Vatsal Goel <144617902+VatsalGoel3@users.noreply.github.com> Date: Wed, 12 Feb 2025 02:36:00 -0700 Subject: [PATCH 2/5] feat(logger): add log buffering module with unit tests --- packages/logger/tests/unit/logBuffer.test.ts | 123 +++++++++++++++++++ 1 file changed, 123 insertions(+) create mode 100644 packages/logger/tests/unit/logBuffer.test.ts diff --git a/packages/logger/tests/unit/logBuffer.test.ts b/packages/logger/tests/unit/logBuffer.test.ts new file mode 100644 index 0000000000..a845433e66 --- /dev/null +++ b/packages/logger/tests/unit/logBuffer.test.ts @@ -0,0 +1,123 @@ +import { describe, expect, it, vi } from 'vitest'; +import { CircularMap, SizedItem, SizedSet } from '../../src/logBuffer'; + +describe('SizedItem', () => { + it('should calculate the byteSize based on JSON serialization', () => { + // Prepare + const logEntry = { message: 'hello world' }; + // Act + const item = new SizedItem(logEntry, 1); + // Assess + const expectedByteSize = Buffer.byteLength(JSON.stringify(logEntry)); + expect(item.byteSize).toBe(expectedByteSize); + }); +}); + +describe('SizedSet', () => { + it('should add an item and update currentBytesSize correctly', () => { + // Prepare + const set = new SizedSet(); + const item = new SizedItem({ test: 'value' }, 1); + // Act + set.add(item); + // Assess + expect(set.currentBytesSize).toBe(item.byteSize); + expect(set.has(item)).toBe(true); + }); + + it('should delete an item and update currentBytesSize correctly', () => { + // Prepare + const set = new SizedSet(); + const item = new SizedItem({ test: 'value' }, 1); + set.add(item); + const initialSize = set.currentBytesSize; + // Act + const result = set.delete(item); + // Assess + expect(result).toBe(true); + expect(set.currentBytesSize).toBe(initialSize - item.byteSize); + expect(set.has(item)).toBe(false); + }); + + it('should clear all items and reset currentBytesSize to 0', () => { + // Prepare + const set = new SizedSet(); + set.add(new SizedItem({ a: 'b' }, 1)); + set.add(new SizedItem({ c: 'd' }, 1)); + // Act + set.clear(); + // Assess + expect(set.currentBytesSize).toBe(0); + expect(set.size).toBe(0); + }); + + it('should remove the first inserted item with shift', () => { + // Prepare + const set = new SizedSet(); + const item1 = new SizedItem({ msg: 'first' }, 1); + const item2 = new SizedItem({ msg: 'second' }, 1); + set.add(item1); + set.add(item2); + // Act + const shiftedItem = set.shift(); + // Assess + expect(shiftedItem).toEqual(item1); + expect(set.has(item1)).toBe(false); + expect(set.currentBytesSize).toBe(item2.byteSize); + }); +}); + +describe('CircularMap', () => { + it('should add items to a new buffer for a given key', () => { + // Prepare + const maxBytes = 200; + const circularMap = new CircularMap({ + maxBytesSize: maxBytes, + }); + // Act + circularMap.setItem('trace-1', { message: 'first log' }, 1); + // Assess + const buffer = circularMap.get('trace-1'); + expect(buffer).toBeDefined(); + if (buffer) { + expect(buffer.currentBytesSize).toBeGreaterThan(0); + expect(buffer.size).toBe(1); + } + }); + + it('should throw an error when an item exceeds maxBytesSize', () => { + // Prepare + const maxBytes = 10; + const circularMap = new CircularMap({ + maxBytesSize: maxBytes, + }); + // Act & Assess + expect(() => { + circularMap.setItem('trace-1', { message: 'a very long message' }, 1); + }).toThrowError('Item too big'); + }); + + it('should evict items when buffer overflows and call the overflow callback', () => { + // Prepare + let overflowCalled = false; + const maxBytes = 100; + const circularMap = new CircularMap({ + maxBytesSize: maxBytes, + onBufferOverflow: () => { + overflowCalled = true; + }, + }); + const smallEntry = { message: 'log' }; + const entryByteSize = Buffer.byteLength(JSON.stringify(smallEntry)); + const entriesCount = Math.ceil(maxBytes / entryByteSize) + 1; + for (let i = 0; i < entriesCount; i++) { + circularMap.setItem('trace-1', smallEntry, 1); + } + // Assess + expect(overflowCalled).toBe(true); + const buffer = circularMap.get('trace-1'); + if (buffer) { + expect(buffer.currentBytesSize).toBeLessThan(maxBytes); + } + }); +}); From ee61392dcf7ea1e8145791adbedfc32b234bc4b0 Mon Sep 17 00:00:00 2001 From: Vatsal Goel <144617902+VatsalGoel3@users.noreply.github.com> Date: Wed, 12 Feb 2025 21:44:02 -0700 Subject: [PATCH 3/5] fix(logger): enforce string values in SizedItem and improve buffer overflow test --- packages/logger/src/logBuffer.ts | 9 +- packages/logger/tests/unit/logBuffer.test.ts | 103 ++++++++++++------- 2 files changed, 68 insertions(+), 44 deletions(-) diff --git a/packages/logger/src/logBuffer.ts b/packages/logger/src/logBuffer.ts index a40de773a5..33d8fc14ef 100644 --- a/packages/logger/src/logBuffer.ts +++ b/packages/logger/src/logBuffer.ts @@ -1,15 +1,16 @@ -import { buffer } from 'node:stream/consumers'; -import { it } from 'node:test'; - +import { isString } from '@aws-lambda-powertools/commons/typeutils'; export class SizedItem { public value: V; public logLevel: number; public byteSize: number; constructor(value: V, logLevel: number) { + if (!isString(value)) { + throw new Error('Value should be a string'); + } this.value = value; this.logLevel = logLevel; - this.byteSize = Buffer.byteLength(JSON.stringify(value)); + this.byteSize = Buffer.byteLength(value as unknown as string); } } diff --git a/packages/logger/tests/unit/logBuffer.test.ts b/packages/logger/tests/unit/logBuffer.test.ts index a845433e66..2e38000df6 100644 --- a/packages/logger/tests/unit/logBuffer.test.ts +++ b/packages/logger/tests/unit/logBuffer.test.ts @@ -2,64 +2,84 @@ import { describe, expect, it, vi } from 'vitest'; import { CircularMap, SizedItem, SizedSet } from '../../src/logBuffer'; describe('SizedItem', () => { - it('should calculate the byteSize based on JSON serialization', () => { + it('calculates the byteSize based on string value', () => { // Prepare - const logEntry = { message: 'hello world' }; + const logEntry = 'hello world'; + // Act const item = new SizedItem(logEntry, 1); + // Assess - const expectedByteSize = Buffer.byteLength(JSON.stringify(logEntry)); + const expectedByteSize = Buffer.byteLength(logEntry); expect(item.byteSize).toBe(expectedByteSize); }); + + it('throws an error if value is not a string', () => { + // Prepare + const invalidValue = { message: 'not a string' }; + + // Act & Assess + expect(() => { + new SizedItem(invalidValue, 1); + }).toThrowError('Value should be a string'); + }); }); describe('SizedSet', () => { - it('should add an item and update currentBytesSize correctly', () => { + it('adds an item and updates currentBytesSize correctly', () => { // Prepare - const set = new SizedSet(); - const item = new SizedItem({ test: 'value' }, 1); + const set = new SizedSet(); + const item = new SizedItem('value', 1); + // Act set.add(item); + // Assess expect(set.currentBytesSize).toBe(item.byteSize); expect(set.has(item)).toBe(true); }); - it('should delete an item and update currentBytesSize correctly', () => { + it('deletes an item and updates currentBytesSize correctly', () => { // Prepare - const set = new SizedSet(); - const item = new SizedItem({ test: 'value' }, 1); + const set = new SizedSet(); + const item = new SizedItem('value', 1); set.add(item); const initialSize = set.currentBytesSize; + // Act const result = set.delete(item); + // Assess expect(result).toBe(true); expect(set.currentBytesSize).toBe(initialSize - item.byteSize); expect(set.has(item)).toBe(false); }); - it('should clear all items and reset currentBytesSize to 0', () => { + it('clears all items and resets currentBytesSize to 0', () => { // Prepare - const set = new SizedSet(); - set.add(new SizedItem({ a: 'b' }, 1)); - set.add(new SizedItem({ c: 'd' }, 1)); + const set = new SizedSet(); + set.add(new SizedItem('b', 1)); + set.add(new SizedItem('d', 1)); + // Act set.clear(); + // Assess expect(set.currentBytesSize).toBe(0); expect(set.size).toBe(0); }); - it('should remove the first inserted item with shift', () => { + it('removes the first inserted item with shift', () => { // Prepare - const set = new SizedSet(); - const item1 = new SizedItem({ msg: 'first' }, 1); - const item2 = new SizedItem({ msg: 'second' }, 1); + const set = new SizedSet(); + const item1 = new SizedItem('first', 1); + const item2 = new SizedItem('second', 1); set.add(item1); set.add(item2); + // Act const shiftedItem = set.shift(); + // Assess expect(shiftedItem).toEqual(item1); expect(set.has(item1)).toBe(false); @@ -68,14 +88,16 @@ describe('SizedSet', () => { }); describe('CircularMap', () => { - it('should add items to a new buffer for a given key', () => { + it('adds items to a new buffer for a given key', () => { // Prepare const maxBytes = 200; - const circularMap = new CircularMap({ + const circularMap = new CircularMap({ maxBytesSize: maxBytes, }); + // Act - circularMap.setItem('trace-1', { message: 'first log' }, 1); + circularMap.setItem('trace-1', 'first log', 1); + // Assess const buffer = circularMap.get('trace-1'); expect(buffer).toBeDefined(); @@ -85,39 +107,40 @@ describe('CircularMap', () => { } }); - it('should throw an error when an item exceeds maxBytesSize', () => { + it('throws an error when an item exceeds maxBytesSize', () => { // Prepare const maxBytes = 10; - const circularMap = new CircularMap({ + const circularMap = new CircularMap({ maxBytesSize: maxBytes, }); + // Act & Assess expect(() => { - circularMap.setItem('trace-1', { message: 'a very long message' }, 1); + circularMap.setItem('trace-1', 'a very long message', 1); }).toThrowError('Item too big'); }); - it('should evict items when buffer overflows and call the overflow callback', () => { + it('evicts items when the buffer overflows and call the overflow callback', () => { // Prepare - let overflowCalled = false; - const maxBytes = 100; - const circularMap = new CircularMap({ - maxBytesSize: maxBytes, - onBufferOverflow: () => { - overflowCalled = true; - }, - }); - const smallEntry = { message: 'log' }; - const entryByteSize = Buffer.byteLength(JSON.stringify(smallEntry)); - const entriesCount = Math.ceil(maxBytes / entryByteSize) + 1; + const options = { + maxBytesSize: 15, + onBufferOverflow: vi.fn(), + }; + const circularMap = new CircularMap(options); + const smallEntry = '12345'; + + const entryByteSize = Buffer.byteLength(smallEntry); + const entriesCount = Math.ceil(options.maxBytesSize / entryByteSize); + + // Act for (let i = 0; i < entriesCount; i++) { circularMap.setItem('trace-1', smallEntry, 1); } + // Assess - expect(overflowCalled).toBe(true); - const buffer = circularMap.get('trace-1'); - if (buffer) { - expect(buffer.currentBytesSize).toBeLessThan(maxBytes); - } + expect(options.onBufferOverflow).toHaveBeenCalledTimes(1); + expect(circularMap.get('trace-1')?.currentBytesSize).toBeLessThan( + options.maxBytesSize + ); }); }); From bb813a6c4c3464df0884512a3b37fd44a9ef2f70 Mon Sep 17 00:00:00 2001 From: Vatsal Goel <144617902+VatsalGoel3@users.noreply.github.com> Date: Wed, 12 Feb 2025 21:51:04 -0700 Subject: [PATCH 4/5] fix(logger): remove unnecessary instantiation in SizedItem test --- packages/logger/tests/unit/logBuffer.test.ts | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/packages/logger/tests/unit/logBuffer.test.ts b/packages/logger/tests/unit/logBuffer.test.ts index 2e38000df6..00d135b5c0 100644 --- a/packages/logger/tests/unit/logBuffer.test.ts +++ b/packages/logger/tests/unit/logBuffer.test.ts @@ -19,9 +19,9 @@ describe('SizedItem', () => { const invalidValue = { message: 'not a string' }; // Act & Assess - expect(() => { - new SizedItem(invalidValue, 1); - }).toThrowError('Value should be a string'); + expect( + () => new SizedItem({ message: 'not a string' } as unknown as string, 1) + ).toThrowError('Value should be a string'); }); }); From e17b3fdfa3608cb82ed068bb5847d8facac24e3a Mon Sep 17 00:00:00 2001 From: Andrea Amorosi Date: Thu, 13 Feb 2025 10:27:49 +0100 Subject: [PATCH 5/5] chore: reliability items --- packages/logger/src/logBuffer.ts | 7 ++++--- packages/logger/tests/unit/logBuffer.test.ts | 4 ++-- 2 files changed, 6 insertions(+), 5 deletions(-) diff --git a/packages/logger/src/logBuffer.ts b/packages/logger/src/logBuffer.ts index 33d8fc14ef..164f3e3735 100644 --- a/packages/logger/src/logBuffer.ts +++ b/packages/logger/src/logBuffer.ts @@ -1,4 +1,5 @@ import { isString } from '@aws-lambda-powertools/commons/typeutils'; + export class SizedItem { public value: V; public logLevel: number; @@ -46,8 +47,8 @@ export class SizedSet extends Set> { } export class CircularMap extends Map> { - #maxBytesSize: number; - #onBufferOverflow?: () => void; + readonly #maxBytesSize: number; + readonly #onBufferOverflow?: () => void; constructor({ maxBytesSize, @@ -82,7 +83,7 @@ export class CircularMap extends Map> { return this; } - #deleteFromBufferUntilSizeIsLessThanMax = ( + readonly #deleteFromBufferUntilSizeIsLessThanMax = ( buffer: SizedSet, item: SizedItem ) => { diff --git a/packages/logger/tests/unit/logBuffer.test.ts b/packages/logger/tests/unit/logBuffer.test.ts index 00d135b5c0..05d930ede2 100644 --- a/packages/logger/tests/unit/logBuffer.test.ts +++ b/packages/logger/tests/unit/logBuffer.test.ts @@ -1,5 +1,5 @@ import { describe, expect, it, vi } from 'vitest'; -import { CircularMap, SizedItem, SizedSet } from '../../src/logBuffer'; +import { CircularMap, SizedItem, SizedSet } from '../../src/logBuffer.js'; describe('SizedItem', () => { it('calculates the byteSize based on string value', () => { @@ -20,7 +20,7 @@ describe('SizedItem', () => { // Act & Assess expect( - () => new SizedItem({ message: 'not a string' } as unknown as string, 1) + () => new SizedItem(invalidValue as unknown as string, 1) ).toThrowError('Value should be a string'); }); });