feat: add diagnostic logging for setter/selectPlacements timing

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,19 +1352,22 @@ class RoktKit implements KitInterface {
   }
 
   public setUserAttribute(key: string, value: unknown): string {
+    this.loggingService?.logDiagnostic(buildSetterDiagnosticLogEntry('setUserAttribute', [key]));
     if (!isSelectPlacementsAttributePersistenceDenied(key)) {
       this.userAttributes[key] = value;
     }
     return 'Successfully set user attribute for forwarder: ' + name;
   }
 
   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<string, unknown> = { ...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

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]');
+    });
+  });
+});

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',
+  };
+}

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', () => {