diff --git a/src/Rokt-Kit.ts b/src/Rokt-Kit.ts index 61fcf8e..9ebcc06 100644 --- a/src/Rokt-Kit.ts +++ b/src/Rokt-Kit.ts @@ -39,6 +39,7 @@ import { import { isLocalStorageAvailable } from './storage'; import { isObject, isString, isEmpty, isFunction, sanitizeUrl } from './utils'; +import { buildSetterDiagnosticLogEntry, buildSelectPlacementsDiagnosticLogEntry } from './diagnosticTiming'; import { createLauncherAttachState, markLauncherAttached, @@ -690,6 +691,10 @@ class ErrorReportingService { class LoggingService { private _transport: ReportingTransport; + // Own ReportingTransport (and thus own RateLimiter) so a burst of + // diagnostic timing entries can't starve the operational INFO budget + // that _transport shares with page-view/quota logging via log(). + private _diagnosticTransport: ReportingTransport; private _loggingUrl: string; private _errorReportingService: { report: (e: ErrorReport) => void }; @@ -702,13 +707,25 @@ class LoggingService { rateLimiter?: RateLimiter, ) { this._transport = new ReportingTransport(config, integrationName, launcherInstanceGuid, accountId, rateLimiter); + this._diagnosticTransport = new ReportingTransport(config, integrationName, launcherInstanceGuid, accountId); this._loggingUrl = generateReportingUrl(config?.loggingUrl, config?.integrationDomain, LOGGING_ENDPOINT); this._errorReportingService = errorReportingService; } log(entry: LogEntry | null | undefined): void { if (!entry) return; - this._transport.send( + this._send(this._transport, entry); + } + + // Ships at INFO severity like log(), but through a separate transport + // instance so it has its own rate-limit budget. + logDiagnostic(entry: LogEntry | null | undefined): void { + if (!entry) return; + this._send(this._diagnosticTransport, entry); + } + + private _send(transport: ReportingTransport, entry: LogEntry): void { + transport.send( this._loggingUrl, WSDKErrorSeverity.INFO, entry.message, @@ -1335,6 +1352,7 @@ class RoktKit implements KitInterface { } public setUserAttribute(key: string, value: unknown): string { + this.loggingService?.logDiagnostic(buildSetterDiagnosticLogEntry('setUserAttribute', [key])); if (!isSelectPlacementsAttributePersistenceDenied(key)) { this.userAttributes[key] = value; } @@ -1342,12 +1360,14 @@ class RoktKit implements KitInterface { } public removeUserAttribute(key: string): string { + this.loggingService?.logDiagnostic(buildSetterDiagnosticLogEntry('removeUserAttribute', [key])); delete this.userAttributes[key]; return 'Successfully removed user attribute for forwarder: ' + name; } private handleIdentityComplete(user: IMParticleUser, callbackName: string): string { this.userAttributes = removeSelectPlacementsAttributePersistenceDeniedAttributes(user.getAllUserAttributes()); + this.loggingService?.logDiagnostic(buildSetterDiagnosticLogEntry(callbackName, Object.keys(this.userAttributes))); return 'Successfully called ' + callbackName + ' for forwarder: ' + name; } @@ -1552,6 +1572,10 @@ class RoktKit implements KitInterface { const selectPlacementsOptions: Record = { ...options, attributes: selectPlacementsAttributes }; + this.loggingService?.logDiagnostic( + buildSelectPlacementsDiagnosticLogEntry(Object.keys(selectPlacementsAttributes)), + ); + const selection = this.launcher!.selectPlacements(selectPlacementsOptions); // After selection resolves, sync the Rokt session ID back to mParticle, then log diff --git a/src/diagnosticTiming.spec.ts b/src/diagnosticTiming.spec.ts new file mode 100644 index 0000000..cb06467 --- /dev/null +++ b/src/diagnosticTiming.spec.ts @@ -0,0 +1,34 @@ +import { describe, it, expect } from 'vitest'; +import { buildSetterDiagnosticLogEntry, buildSelectPlacementsDiagnosticLogEntry } from './diagnosticTiming'; + +describe('diagnosticTiming', () => { + describe('buildSetterDiagnosticLogEntry', () => { + it('reports the source and attribute keys', () => { + const entry = buildSetterDiagnosticLogEntry('setUserAttribute', ['favoriteColor']); + + expect(entry.code).toBe('ATTRIBUTE_SETTER_CALLED'); + expect(entry.message).toBe('Rokt Kit: setUserAttribute called [attributeKeys=favoriteColor]'); + }); + + it('joins multiple attribute keys', () => { + const entry = buildSetterDiagnosticLogEntry('onUserIdentified', ['email', 'firstName']); + + expect(entry.message).toContain('[attributeKeys=email,firstName]'); + }); + + it('never includes attribute values, only keys', () => { + const entry = buildSetterDiagnosticLogEntry('setUserAttribute', ['email']); + + expect(entry.message).not.toContain('test@example.com'); + }); + }); + + describe('buildSelectPlacementsDiagnosticLogEntry', () => { + it('reports the full set of placement attribute keys', () => { + const entry = buildSelectPlacementsDiagnosticLogEntry(['favoriteColor', 'mpid']); + + expect(entry.code).toBe('SELECT_PLACEMENTS_DISPATCHED'); + expect(entry.message).toBe('Rokt Kit: selectPlacements dispatched [placementAttributeKeys=favoriteColor,mpid]'); + }); + }); +}); diff --git a/src/diagnosticTiming.ts b/src/diagnosticTiming.ts new file mode 100644 index 0000000..702b484 --- /dev/null +++ b/src/diagnosticTiming.ts @@ -0,0 +1,26 @@ +// Builds diagnostic log entries for attribute/identity setter calls and +// selectPlacements dispatches. Each fires independently at the moment it +// happens; correlating the two (timing delta, which setters preceded a given +// placement call) is done downstream from the logged timestamps and page URL +// that ReportingTransport already attaches to every log request. Attribute +// names only — never values — since this ships over the network logging +// pipeline and setter payloads can carry customer PII. + +export interface DiagnosticLogEntry { + message: string; + code: string; +} + +export function buildSetterDiagnosticLogEntry(source: string, attributeKeys: string[]): DiagnosticLogEntry { + return { + message: `Rokt Kit: ${source} called [attributeKeys=${attributeKeys.join(',')}]`, + code: 'ATTRIBUTE_SETTER_CALLED', + }; +} + +export function buildSelectPlacementsDiagnosticLogEntry(placementAttributeKeys: string[]): DiagnosticLogEntry { + return { + message: `Rokt Kit: selectPlacements dispatched [placementAttributeKeys=${placementAttributeKeys.join(',')}]`, + code: 'SELECT_PLACEMENTS_DISPATCHED', + }; +} diff --git a/test/src/tests.spec.ts b/test/src/tests.spec.ts index aeaae16..84d37a2 100644 --- a/test/src/tests.spec.ts +++ b/test/src/tests.spec.ts @@ -943,6 +943,40 @@ describe('Rokt Forwarder', () => { }); }); + it('should log a diagnostic entry with the full set of placement attribute keys, independent of any setter log', async () => { + await (window as any).mParticle.forwarder.init( + { + accountId: '123456', + }, + reportService.cb, + true, + null, + {}, + ); + + const logDiagnosticSpy = vi.spyOn((window as any).mParticle.forwarder.loggingService, 'logDiagnostic'); + + (window as any).mParticle.forwarder.setUserAttribute('favoriteColor', 'blue'); + + await (window as any).mParticle.forwarder.selectPlacements({ + identifier: 'test-placement', + attributes: { test: 'test' }, + }); + + // One log for the setter call, one for the selectPlacements dispatch — no correlation between them. + expect(logDiagnosticSpy).toHaveBeenCalledTimes(2); + expect(logDiagnosticSpy).toHaveBeenCalledWith( + expect.objectContaining({ message: 'Rokt Kit: setUserAttribute called [attributeKeys=favoriteColor]' }), + ); + const dispatchEntry = logDiagnosticSpy.mock.calls.find( + (call) => call[0].code === 'SELECT_PLACEMENTS_DISPATCHED', + )?.[0]; + expect(dispatchEntry.message).toContain('placementAttributeKeys='); + expect(dispatchEntry.message).toContain('favoriteColor'); + expect(dispatchEntry.message).not.toContain('blue'); + logDiagnosticSpy.mockRestore(); + }); + it('should send the mParticle session id current at the time of each call', async () => { let currentSessionId = 'first-mp-session'; (window as any).mParticle.sessionManager = { @@ -3647,6 +3681,31 @@ describe('Rokt Forwarder', () => { 'test-attribute': 'test-value', }); }); + + it('should log a diagnostic entry with the attribute key but not its value', async () => { + const logDiagnosticSpy = vi.spyOn((window as any).mParticle.forwarder.loggingService, 'logDiagnostic'); + + (window as any).mParticle.forwarder.setUserAttribute('test-attribute', 'sensitive-value'); + + expect(logDiagnosticSpy).toHaveBeenCalledWith( + expect.objectContaining({ + code: 'ATTRIBUTE_SETTER_CALLED', + message: 'Rokt Kit: setUserAttribute called [attributeKeys=test-attribute]', + }), + ); + logDiagnosticSpy.mockRestore(); + }); + + it('should log a diagnostic entry even for a denylisted attribute key', async () => { + const logDiagnosticSpy = vi.spyOn((window as any).mParticle.forwarder.loggingService, 'logDiagnostic'); + + (window as any).mParticle.forwarder.setUserAttribute('confirmationRef', 'order-123'); + + expect(logDiagnosticSpy).toHaveBeenCalledWith( + expect.objectContaining({ message: 'Rokt Kit: setUserAttribute called [attributeKeys=confirmationRef]' }), + ); + logDiagnosticSpy.mockRestore(); + }); }); describe('#removeUserAttribute', () => { @@ -3657,6 +3716,20 @@ describe('Rokt Forwarder', () => { expect((window as any).mParticle.forwarder.userAttributes).toEqual({}); }); + + it('should log a diagnostic entry for the removed key', async () => { + const logDiagnosticSpy = vi.spyOn((window as any).mParticle.forwarder.loggingService, 'logDiagnostic'); + + (window as any).mParticle.forwarder.removeUserAttribute('test-attribute'); + + expect(logDiagnosticSpy).toHaveBeenCalledWith( + expect.objectContaining({ + code: 'ATTRIBUTE_SETTER_CALLED', + message: 'Rokt Kit: removeUserAttribute called [attributeKeys=test-attribute]', + }), + ); + logDiagnosticSpy.mockRestore(); + }); }); describe('#onUserIdentified', () => { @@ -3679,6 +3752,30 @@ describe('Rokt Forwarder', () => { expect((window as any).mParticle.forwarder.filters.filteredUser.getMPID()).toBe('123'); }); + it('should log a diagnostic entry with the resulting attribute keys but not their values', () => { + const logDiagnosticSpy = vi.spyOn((window as any).mParticle.forwarder.loggingService, 'logDiagnostic'); + + (window as any).mParticle.forwarder.onUserIdentified({ + getAllUserAttributes: function () { + return { email: 'test@example.com' }; + }, + getMPID: function () { + return '123'; + }, + getUserIdentities: function () { + return { userIdentities: {} }; + }, + }); + + expect(logDiagnosticSpy).toHaveBeenCalledWith( + expect.objectContaining({ + code: 'ATTRIBUTE_SETTER_CALLED', + message: 'Rokt Kit: onUserIdentified called [attributeKeys=email]', + }), + ); + logDiagnosticSpy.mockRestore(); + }); + it('should not cache denylisted commerce attributes from the filtered user', () => { (window as any).mParticle.forwarder.onUserIdentified({ getAllUserAttributes: function () { @@ -4357,6 +4454,24 @@ describe('Rokt Forwarder', () => { 'user-attr': 'user-value', }); }); + + it('should log a diagnostic entry sourced as onLoginComplete', () => { + const logDiagnosticSpy = vi.spyOn((window as any).mParticle.forwarder.loggingService, 'logDiagnostic'); + + (window as any).mParticle.forwarder.onLoginComplete({ + getAllUserAttributes: function () { + return { 'user-attr': 'user-value' }; + }, + getMPID: function () { + return '123'; + }, + }); + + expect(logDiagnosticSpy).toHaveBeenCalledWith( + expect.objectContaining({ message: 'Rokt Kit: onLoginComplete called [attributeKeys=user-attr]' }), + ); + logDiagnosticSpy.mockRestore(); + }); }); describe('#onLogoutComplete', () => { @@ -4374,6 +4489,24 @@ describe('Rokt Forwarder', () => { 'remaining-attr': 'some-value', }); }); + + it('should log a diagnostic entry sourced as onLogoutComplete', () => { + const logDiagnosticSpy = vi.spyOn((window as any).mParticle.forwarder.loggingService, 'logDiagnostic'); + + (window as any).mParticle.forwarder.onLogoutComplete({ + getAllUserAttributes: function () { + return { 'remaining-attr': 'some-value' }; + }, + getMPID: function () { + return '123'; + }, + }); + + expect(logDiagnosticSpy).toHaveBeenCalledWith( + expect.objectContaining({ message: 'Rokt Kit: onLogoutComplete called [attributeKeys=remaining-attr]' }), + ); + logDiagnosticSpy.mockRestore(); + }); }); describe('#onModifyComplete', () => { @@ -4394,6 +4527,27 @@ describe('Rokt Forwarder', () => { 'modified-attr': 'modified-value', }); }); + + it('should log a diagnostic entry sourced as onModifyComplete', () => { + const logDiagnosticSpy = vi.spyOn((window as any).mParticle.forwarder.loggingService, 'logDiagnostic'); + + (window as any).mParticle.forwarder.onModifyComplete({ + getAllUserAttributes: function () { + return { 'modified-attr': 'modified-value' }; + }, + getMPID: function () { + return '123'; + }, + getUserIdentities: function () { + return { userIdentities: {} }; + }, + }); + + expect(logDiagnosticSpy).toHaveBeenCalledWith( + expect.objectContaining({ message: 'Rokt Kit: onModifyComplete called [attributeKeys=modified-attr]' }), + ); + logDiagnosticSpy.mockRestore(); + }); }); describe('#fetchOptimizely', () => { @@ -7935,6 +8089,43 @@ describe('Rokt Forwarder', () => { service.log(null); expect(fetchCalls.length).toBe(0); }); + + it('logDiagnostic should send to the logging endpoint with severity INFO', () => { + const errorService = new ErrorReportingServiceClass({ isLoggingEnabled: true }, '1.0.0', 'test-guid'); + const service = new LoggingServiceClass( + { loggingUrl: 'test.com/v1/log', isLoggingEnabled: true }, + errorService, + '1.0.0', + 'test-guid', + ); + service.logDiagnostic({ message: 'diagnostic entry', code: 'SELECT_PLACEMENTS_SETTER_TIMING' }); + expect(fetchCalls.length).toBe(1); + const body = JSON.parse(fetchCalls[0].options.body); + expect(body.severity).toBe('INFO'); + expect(body.additionalInformation.message).toBe('diagnostic entry'); + }); + + it('logDiagnostic should not share its rate-limit budget with log()', () => { + const errorService = new ErrorReportingServiceClass({ isLoggingEnabled: true }, '1.0.0', 'test-guid'); + const service = new LoggingServiceClass( + { loggingUrl: 'test.com/v1/log', isLoggingEnabled: true }, + errorService, + '1.0.0', + 'test-guid', + ); + + // Exhaust log()'s INFO budget. + for (let i = 0; i < 10; i++) { + service.log({ message: 'operational log ' + i }); + } + expect(fetchCalls.length).toBe(10); + service.log({ message: 'rate limited operational log' }); + expect(fetchCalls.length).toBe(10); + + // logDiagnostic still gets through on its own budget. + service.logDiagnostic({ message: 'diagnostic entry', code: 'SELECT_PLACEMENTS_SETTER_TIMING' }); + expect(fetchCalls.length).toBe(11); + }); }); describe('RateLimiter', () => {