diff --git a/packages/dd-trace/src/openfeature/writers/base.js b/packages/dd-trace/src/openfeature/writers/base.js index c0007c2963b..5926ae3f554 100644 --- a/packages/dd-trace/src/openfeature/writers/base.js +++ b/packages/dd-trace/src/openfeature/writers/base.js @@ -58,7 +58,8 @@ class BaseFFEWriter { this._buffer = [] this._bufferLimit = 1000 - this._bufferSize = 0 + this._bufferStart = 0 + this._dropWarningLogged = false this._config = config this._endpoint = endpoint @@ -99,51 +100,87 @@ class BaseFFEWriter { const eventArray = Array.isArray(events) ? events : [events] for (const event of eventArray) { - if (this._buffer.length >= this._bufferLimit) { - log.warn('%s event buffer full (limit is %d), dropping event', this.constructor.name, this._bufferLimit) - this._droppedEvents++ - continue - } - - const eventSizeBytes = Buffer.byteLength(JSON.stringify(event)) - - // Check individual event size limit if configured - if (this._eventSizeLimit && eventSizeBytes > this._eventSizeLimit) { - log.warn('%s event size %d bytes exceeds limit %d, dropping event', - this.constructor.name, eventSizeBytes, this._eventSizeLimit) + if (this._buffer.length < this._bufferLimit) { + this._buffer.push(event) + } else { + this._buffer[this._bufferStart] = event + this._bufferStart = (this._bufferStart + 1) % this._bufferLimit this._droppedEvents++ - continue - } - // Check if adding this event would exceed payload size limit if configured - if (this._payloadSizeLimit && this._bufferSize + eventSizeBytes > this._payloadSizeLimit) { - log.debug('%s buffer size would exceed %d bytes, flushing first', this.constructor.name, this._payloadSizeLimit) - this.flush() + if (!this._dropWarningLogged) { + this._dropWarningLogged = true + log.warn( + '%s dropped exposure event(s) at cap %d. This may invalidate experiment results.', + this.constructor.name, + this._bufferLimit + ) + } } - - this._bufferSize += eventSizeBytes - this._buffer.push(event) } } /** - * Flushes all buffered events to the agent + * Sizes, batches, and flushes all buffered events. */ flush () { if (this._buffer.length === 0) { return } - const events = this._buffer + + const events = this._bufferStart === 0 + ? this._buffer + : [...this._buffer.slice(this._bufferStart), ...this._buffer.slice(0, this._bufferStart)] this._buffer = [] - this._bufferSize = 0 + this._bufferStart = 0 - const payload = this._encode(this.makePayload(events)) + let batch = [] + let batchSize = 0 - // eslint-disable-next-line eslint-rules/eslint-log-printf-style - log.debug(() => `${this.constructor.name} flushing payload: ${safeJSONStringify(payload)}`) + for (const event of events) { + let eventSize + try { + eventSize = Buffer.byteLength(JSON.stringify(event)) + } catch (error) { + log.warn('%s could not serialize an event, dropping event: %s', this.constructor.name, error.message) + this._droppedEvents++ + continue + } - const route = this.#createActiveRoute() - this.#sendRequest(payload, events.length, route, this._fallbackRoute) + if (this._eventSizeLimit && eventSize > this._eventSizeLimit) { + log.warn( + '%s event size %d bytes exceeds limit %d, dropping event', + this.constructor.name, + eventSize, + this._eventSizeLimit + ) + this._droppedEvents++ + continue + } + + if (this._payloadSizeLimit && eventSize > this._payloadSizeLimit) { + log.warn( + '%s event size %d bytes exceeds payload limit %d, dropping event', + this.constructor.name, + eventSize, + this._payloadSizeLimit + ) + this._droppedEvents++ + continue + } + + if (batch.length > 0 && this._payloadSizeLimit && batchSize + eventSize > this._payloadSizeLimit) { + this.#send(batch) + batch = [] + batchSize = 0 + } + + batch.push(event) + batchSize += eventSize + } + + if (batch.length > 0) { + this.#send(batch) + } } /** @@ -194,6 +231,34 @@ class BaseFFEWriter { this._fallbackRoute = fallbackRoute ? this.#createRoute(fallbackRoute) : undefined } + /** + * Sends one event batch. + * + * @param {Array} events - Events in the batch + * @returns {void} + */ + #send (events) { + let payload + try { + payload = this._encode(this.makePayload(events)) + } catch (error) { + log.warn( + '%s could not encode %d event(s), dropping batch: %s', + this.constructor.name, + events.length, + error.message + ) + this._droppedEvents += events.length + return + } + + // eslint-disable-next-line eslint-rules/eslint-log-printf-style + log.debug(() => `${this.constructor.name} flushing payload: ${safeJSONStringify(payload)}`) + + const route = this.#createActiveRoute() + this.#sendRequest(payload, events.length, route, this._fallbackRoute) + } + /** * Creates request state for a configured writer route. * diff --git a/packages/dd-trace/src/openfeature/writers/exposures.js b/packages/dd-trace/src/openfeature/writers/exposures.js index c41d344d71f..1eea3a92fa1 100644 --- a/packages/dd-trace/src/openfeature/writers/exposures.js +++ b/packages/dd-trace/src/openfeature/writers/exposures.js @@ -11,14 +11,8 @@ const { EVP_SUBDOMAIN_HEADER_NAME, } = require('../../evp_proxy/constants') const { joinEVPProxyPath } = require('../../evp_proxy/path') -const log = require('../../log') const BaseFFEWriter = require('./base') -// Disabled-state cap. Drops invalidate experiment results because the provider's -// exposure dedupe cache keeps masking dropped events after recovery. The first -// drop emits a warning and `droppedEventCount` accumulates the cumulative loss. -const PENDING_MAX_EVENTS = 1000 - /** * @typedef {object} ExposureRoute * @property {URL} url - Route base URL @@ -63,14 +57,14 @@ class ExposuresWriter extends BaseFFEWriter { // Disabled until route selection resolves. #enabled = false - /** @type {ExposureEvent[]} */ - #pendingEvents = [] + #routeResolved = false + + /** @type {ReturnType | undefined} */ + #startupFlushImmediate /** @type {ExposureContext} */ #context - #dropWarned = false - /** * @param {import('../../config/config-base')} config - Tracer configuration object * @param {ExposureRoute} [route] - Caller-supplied route @@ -116,16 +110,20 @@ class ExposuresWriter extends BaseFFEWriter { * @returns {void} */ setEnabled (enabled, route) { + this.#routeResolved = true + if (route) { this.#setRoute(route) } this.#enabled = enabled - if (enabled && this.#pendingEvents.length > 0) { - // Flush all pending events as a batch - super.append(this.#pendingEvents) - this.#pendingEvents = [] + if (enabled) { + this.#scheduleStartupFlush() + } else { + this.#cancelStartupFlush() + this._buffer = [] + this._bufferStart = 0 } } @@ -155,50 +153,57 @@ class ExposuresWriter extends BaseFFEWriter { } /** - * Appends exposure event(s) to the buffer + * Appends exposure event(s) to the buffer. + * * @param {ExposureEvent|ExposureEvent[]} events - Exposure event(s) to append + * @returns {void} */ append (events) { - if (this.#enabled) { - super.append(events) - return - } + if (this.#routeResolved && !this.#enabled) return - const eventArray = Array.isArray(events) ? events : [events] - this.#pendingEvents.push(...eventArray) - if (this.#pendingEvents.length > PENDING_MAX_EVENTS) { - const dropped = this.#pendingEvents.length - PENDING_MAX_EVENTS - this.#pendingEvents.splice(0, dropped) - this._droppedEvents += dropped - if (!this.#dropWarned) { - this.#dropWarned = true - log.warn( - '%s dropped exposure event(s) at cap %d. This may invalidate experiment results.', - this.constructor.name, PENDING_MAX_EVENTS) - } - } + super.append(events) } /** - * @returns {number} Cumulative number of exposure events dropped due to buffer overflow. + * Flushes buffered exposure events through the selected route. + * + * @returns {void} */ - get droppedEventCount () { - return this._droppedEvents + flush () { + if (!this.#enabled) return + + this.#cancelStartupFlush() + super.flush() } /** - * Flushes buffered exposure events to the agent + * Flushes startup events after route selection completes. + * + * @returns {void} */ - flush () { - if (!this.#enabled) { - return - } - super.flush() + #scheduleStartupFlush () { + if (this.#startupFlushImmediate || this._buffer.length === 0) return + + this.#startupFlushImmediate = setImmediate(() => { + this.#startupFlushImmediate = undefined + this.flush() + }) + } + + /** + * Cancels a scheduled drain. + * + * @returns {void} + */ + #cancelStartupFlush () { + if (!this.#startupFlushImmediate) return + clearImmediate(this.#startupFlushImmediate) + this.#startupFlushImmediate = undefined } /** * Formats exposure events with service context metadata - * @param {Array} events - Array of exposure events + * @param {Array} events - Array of exposure events to format * @returns {ExposureEventPayload} Formatted payload with service context */ makePayload (events) { diff --git a/packages/dd-trace/test/openfeature/writers/exposures.spec.js b/packages/dd-trace/test/openfeature/writers/exposures.spec.js index 127ad77f58e..29c7ed2d7d2 100644 --- a/packages/dd-trace/test/openfeature/writers/exposures.spec.js +++ b/packages/dd-trace/test/openfeature/writers/exposures.spec.js @@ -87,51 +87,90 @@ describe('OpenFeature Exposures Writer', () => { }) describe('append', () => { - beforeEach(() => { - writer.setEnabled(true) // Enable writer for append tests - }) - - it('should add exposure event to buffer', () => { + it('should enqueue exposure events without waiting for another event loop turn', () => { + writer.setEnabled(true) writer.append(exposureEvent) assert.strictEqual(writer._buffer?.length, 1) assert.strictEqual(writer._buffer[0], exposureEvent) + sinon.assert.notCalled(request) }) - it('should track buffer size', () => { - const initialSize = writer._bufferSize + it('should defer event serialization until flush', () => { + writer.setEnabled(true) + const toJSON = sinon.spy(() => exposureEvent) + const event = { ...exposureEvent, toJSON } - writer.append(exposureEvent) + writer.append(event) + sinon.assert.notCalled(toJSON) - assert.ok(writer._bufferSize > initialSize, `Expected ${writer._bufferSize} > ${initialSize}`) + writer.flush() + sinon.assert.calledOnce(toJSON) }) - it('should drop events when buffer is full', () => { + it('should retain the newest events when the buffer is full', () => { + writer.setEnabled(true) writer._bufferLimit = 2 - writer.append(exposureEvent) - writer.append(exposureEvent) - writer.append(exposureEvent) // Should be dropped + writer.append([ + { ...exposureEvent, sequence: 1 }, + { ...exposureEvent, sequence: 2 }, + { ...exposureEvent, sequence: 3 }, + ]) assert.strictEqual(writer._buffer?.length, 2) + assert.strictEqual(writer._bufferStart, 1) + assert.deepStrictEqual( + [...writer._buffer.slice(writer._bufferStart), ...writer._buffer.slice(0, writer._bufferStart)] + .map(event => event.sequence), + [2, 3] + ) assert.strictEqual(writer._droppedEvents, 1) sinon.assert.calledOnce(log.warn) }) - it('should drop events exceeding 1MB size limit', () => { + it('should use one queue across event loop turns', async () => { + writer.setEnabled(true) + writer._bufferLimit = 2 + + writer.append([ + { ...exposureEvent, sequence: 1 }, + { ...exposureEvent, sequence: 2 }, + ]) + await clock.tickAsync(0) + writer.append([ + { ...exposureEvent, sequence: 3 }, + { ...exposureEvent, sequence: 4 }, + ]) + + assert.deepStrictEqual( + [...writer._buffer.slice(writer._bufferStart), ...writer._buffer.slice(0, writer._bufferStart)] + .map(event => event.sequence), + [3, 4] + ) + assert.strictEqual(writer._droppedEvents, 2) + }) + + it('should drop events exceeding 1MB size limit during flush', () => { + writer.setEnabled(true) const largeEvent = { ...exposureEvent, largeData: 'x'.repeat(1024 * 1024 + 1), // > 1MB } writer.append(largeEvent) + assert.strictEqual(writer._buffer?.length, 1) + assert.strictEqual(writer._droppedEvents, 0) + + writer.flush() assert.strictEqual(writer._buffer?.length, 0) assert.strictEqual(writer._droppedEvents, 1) sinon.assert.calledWith(log.warn, sinon.match(/event size[\s\S]*bytes exceeds limit/)) }) - it('should flush when payload would exceed 5MB limit', () => { + it('should split buffered events into payload-size batches during flush', () => { + writer.setEnabled(true) // Create events that together exceed 5MB (limit is 5242880 bytes) // Individual event limit is (1MB - 1KB) = 1047552 bytes // Use ~1020KB events to safely stay under individual limit @@ -140,77 +179,70 @@ describe('OpenFeature Exposures Writer', () => { largeData: 'x'.repeat(1020 * 1024), // ~1020KB each } - // Add 5 events (~5MB total) - // Events 1-5 should accumulate and not trigger flush - for (let i = 0; i < 5; i++) { + for (let i = 0; i < 6; i++) { writer.append(largeEvent) assert.strictEqual(writer._buffer.length, i + 1, `Buffer should contain ${i + 1} event(s) after appending event ${i + 1}`) } - // Verify request was not called yet sinon.assert.notCalled(request) + writer.flush() - // Add 6th event (~6MB total) - should trigger flush - writer.append(largeEvent) - // Verify request was called (flush happened when limit was reached) - sinon.assert.called(request) - // 6th event should have triggered flush, leaving only the new event - assert.strictEqual(writer._buffer.length, 1, - 'Buffer should contain 1 event after flush was triggered by 6th event') + sinon.assert.calledTwice(request) + assert.strictEqual(JSON.parse(request.firstCall.args[0]).exposures.length, 5) + assert.strictEqual(JSON.parse(request.secondCall.args[0]).exposures.length, 1) + assert.strictEqual(writer._buffer.length, 0) }) - it('should buffer events while disabled and drain on enable', () => { - writer.setEnabled(false) + it('should buffer events while the startup route is unresolved and flush on enable', async () => { writer.append(exposureEvent) - // Pending events stay out of the main buffer until enable. - assert.strictEqual(writer._buffer.length, 0) + assert.strictEqual(writer._buffer.length, 1) writer.setEnabled(true) - assert.strictEqual(writer._buffer.length, 1) - assert.strictEqual(writer._buffer[0], exposureEvent) - }) + await clock.tickAsync(0) - it('should keep every pending event when count equals the cap', () => { - writer.setEnabled(false) + assert.strictEqual(writer._buffer.length, 0) + sinon.assert.calledOnce(request) + }) + it('should keep every event when count equals the cap', () => { const cap = 1000 const events = [] for (let i = 0; i < cap; i++) { events.push({ ...exposureEvent, seq: i }) } writer.append(events) - writer.setEnabled(true) assert.strictEqual(writer._buffer.length, cap) - assert.strictEqual(writer.droppedEventCount, 0) + assert.strictEqual(writer._droppedEvents, 0) sinon.assert.notCalled(log.warn) }) - it('should drop oldest pending events one past the cap', () => { - writer.setEnabled(false) - + it('should drop the oldest event one past the cap', () => { const cap = 1000 const events = [] for (let i = 0; i < cap + 1; i++) { - events.push({ ...exposureEvent, seq: i }) + events.push({ + ...exposureEvent, + subject: { ...exposureEvent.subject, id: `user-${i}` }, + }) } - writer.append(events) writer.setEnabled(true) + writer.append(events) + writer.flush() - assert.strictEqual(writer._buffer.length, cap) - assert.strictEqual(writer._buffer[0].seq, 1) - assert.strictEqual(writer._buffer.at(-1).seq, cap) - assert.strictEqual(writer.droppedEventCount, 1) + const payload = JSON.parse(request.firstCall.args[0]) + assert.strictEqual(payload.exposures.length, cap) + assert.strictEqual(payload.exposures[0].subject.id, 'user-1') + assert.strictEqual(payload.exposures.at(-1).subject.id, `user-${cap}`) + assert.strictEqual(writer._droppedEvents, 1) sinon.assert.calledOnce(log.warn) assert.match(format(...log.warn.firstCall.args), /dropped exposure event\(s\) at cap 1000/) }) it('should throttle the drop warning while still counting every dropped event', () => { - writer.setEnabled(false) - const cap = 1000 const events = [] for (let i = 0; i < cap + 1; i++) { @@ -220,9 +252,20 @@ describe('OpenFeature Exposures Writer', () => { writer.append({ ...exposureEvent, seq: cap + 1 }) writer.append({ ...exposureEvent, seq: cap + 2 }) - assert.strictEqual(writer.droppedEventCount, 3) + assert.strictEqual(writer._droppedEvents, 3) sinon.assert.calledOnce(log.warn) }) + + it('should discard pending and future events after route resolution fails', async () => { + writer.append(exposureEvent) + writer.setEnabled(false) + writer.append(exposureEvent) + writer.setEnabled(true) + await clock.tickAsync(0) + + assert.strictEqual(writer._buffer.length, 0) + sinon.assert.notCalled(request) + }) }) describe('makePayload', () => { @@ -506,7 +549,7 @@ describe('OpenFeature Exposures Writer', () => { writer.flush() assert.strictEqual(writer._buffer?.length, 0) - assert.strictEqual(writer._bufferSize, 0) + assert.strictEqual(writer._bufferStart, 0) }) it('should log errors on request failure', (done) => {