ref(node): Improve span flushing (#16577)

Follow up to #16416,
slightly moving things around and making some small improvements to
performance and logic (some not related to that PR but another
improvement we noticed when BYK looked int this):

1. Actually debounce the flushing properly, including a maxWait of
100ms. Previously, it was technically possible to debounce flushing
forever, if a span was flushed every ms. Now, at least after 100ms it
should _always_ flush.
2. Simplify overhead by avoid checking for the 5min timeout of sent
spans. As this check `isSpanAlreadySent` has been called for every
single span that ended, it is quite high impact, and meant a little bit
of additional work (although it should not necessarily run _too_ often,
but still). Instead, we now simply check for `map.has(id)` which should
be good enough for what we want to achieve, IMHO. We still clean up the
sent spans when flushing, so old stuff should still go away eventually.
3. Made stuff that is not needed as public API private on the span
exporter class. this is technically breaking but I think it is OK, this
should not be public API surface as it does not need to be called from
outside.

For this I moved the already existing `debounce` function from replay to
core. We re-implement this in replay with a different setTimeout impl.
which is needed for some angular stuff.

---------

Co-authored-by: Abhijeet Prasad <[email protected]>

Author: mydea

packages/core/src/index.ts

@@ -88,6 +88,7 @@ export { parseSampleRate } from './utils/parseSampleRate';
 export { applySdkMetadata } from './utils/sdkMetadata';
 export { getTraceData } from './utils/traceData';
 export { getTraceMetaTags } from './utils/meta';
+export { debounce } from './utils/debounce';
 export {
   winterCGHeadersToDict,
   winterCGRequestToRequestData,

packages/core/src/utils/debounce.ts

@@ -0,0 +1,76 @@
+type DebouncedCallback = {
+  (): void | unknown;
+  flush: () => void | unknown;
+  cancel: () => void;
+};
+type CallbackFunction = () => unknown;
+type DebounceOptions = {
+  /** The max. time in ms to wait for the callback to be invoked. */
+  maxWait?: number;
+  /** This can be overwritten to use a different setTimeout implementation, e.g. to avoid triggering change detection in Angular  */
+  setTimeoutImpl?: typeof setTimeout;
+};
+
+/**
+ * Heavily simplified debounce function based on lodash.debounce.
+ *
+ * This function takes a callback function (@param fun) and delays its invocation
+ * by @param wait milliseconds. Optionally, a maxWait can be specified in @param options,
+ * which ensures that the callback is invoked at least once after the specified max. wait time.
+ *
+ * @param func the function whose invocation is to be debounced
+ * @param wait the minimum time until the function is invoked after it was called once
+ * @param options the options object, which can contain the `maxWait` property
+ *
+ * @returns the debounced version of the function, which needs to be called at least once to start the
+ *          debouncing process. Subsequent calls will reset the debouncing timer and, in case @paramfunc
+ *          was already invoked in the meantime, return @param func's return value.
+ *          The debounced function has two additional properties:
+ *          - `flush`: Invokes the debounced function immediately and returns its return value
+ *          - `cancel`: Cancels the debouncing process and resets the debouncing timer
+ */
+export function debounce(func: CallbackFunction, wait: number, options?: DebounceOptions): DebouncedCallback {
+  let callbackReturnValue: unknown;
+
+  let timerId: ReturnType<typeof setTimeout> | undefined;
+  let maxTimerId: ReturnType<typeof setTimeout> | undefined;
+
+  const maxWait = options?.maxWait ? Math.max(options.maxWait, wait) : 0;
+  const setTimeoutImpl = options?.setTimeoutImpl || setTimeout;
+
+  function invokeFunc(): unknown {
+    cancelTimers();
+    callbackReturnValue = func();
+    return callbackReturnValue;
+  }
+
+  function cancelTimers(): void {
+    timerId !== undefined && clearTimeout(timerId);
+    maxTimerId !== undefined && clearTimeout(maxTimerId);
+    timerId = maxTimerId = undefined;
+  }
+
+  function flush(): unknown {
+    if (timerId !== undefined || maxTimerId !== undefined) {
+      return invokeFunc();
+    }
+    return callbackReturnValue;
+  }
+
+  function debounced(): unknown {
+    if (timerId) {
+      clearTimeout(timerId);
+    }
+    timerId = setTimeoutImpl(invokeFunc, wait);
+
+    if (maxWait && maxTimerId === undefined) {
+      maxTimerId = setTimeoutImpl(invokeFunc, maxWait);
+    }
+
+    return callbackReturnValue;
+  }
+
+  debounced.cancel = cancelTimers;
+  debounced.flush = flush;
+  return debounced;
+}

packages/core/test/lib/utils/debounce.test.ts

@@ -0,0 +1,276 @@
+import { beforeAll, describe, expect, it, vi } from 'vitest';
+import { debounce } from '../../../src/utils/debounce';
+
+describe('Unit | util | debounce', () => {
+  beforeAll(() => {
+    vi.useFakeTimers();
+  });
+
+  it('delay the execution of the passed callback function by the passed minDelay', () => {
+    const callback = vi.fn();
+    const debouncedCallback = debounce(callback, 100);
+    debouncedCallback();
+    expect(callback).not.toHaveBeenCalled();
+
+    vi.advanceTimersByTime(99);
+    expect(callback).not.toHaveBeenCalled();
+
+    vi.advanceTimersByTime(1);
+    expect(callback).toHaveBeenCalled();
+  });
+
+  it('should invoke the callback at latest by maxWait, if the option is specified', () => {
+    const callback = vi.fn();
+    const debouncedCallback = debounce(callback, 100, { maxWait: 150 });
+    debouncedCallback();
+    expect(callback).not.toHaveBeenCalled();
+
+    vi.advanceTimersByTime(98);
+    expect(callback).not.toHaveBeenCalled();
+
+    debouncedCallback();
+
+    vi.advanceTimersByTime(1);
+    expect(callback).not.toHaveBeenCalled();
+
+    vi.advanceTimersByTime(49);
+    // at this time, the callback shouldn't be invoked and with a new call, it should be debounced further.
+    debouncedCallback();
+    expect(callback).not.toHaveBeenCalled();
+
+    // But because the maxWait is reached, the callback should nevertheless be invoked.
+    vi.advanceTimersByTime(10);
+    expect(callback).toHaveBeenCalled();
+  });
+
+  it('should not invoke the callback as long as it is debounced and no maxWait option is specified', () => {
+    const callback = vi.fn();
+    const debouncedCallback = debounce(callback, 100);
+    debouncedCallback();
+    expect(callback).not.toHaveBeenCalled();
+
+    vi.advanceTimersByTime(99);
+    expect(callback).not.toHaveBeenCalled();
+
+    debouncedCallback();
+
+    vi.advanceTimersByTime(1);
+    expect(callback).not.toHaveBeenCalled();
+
+    vi.advanceTimersByTime(98);
+    debouncedCallback();
+    expect(callback).not.toHaveBeenCalled();
+
+    vi.advanceTimersByTime(99);
+    expect(callback).not.toHaveBeenCalled();
+    debouncedCallback();
+
+    vi.advanceTimersByTime(100);
+    expect(callback).toHaveBeenCalled();
+  });
+
+  it('should invoke the callback as soon as callback.flush() is called', () => {
+    const callback = vi.fn();
+    const debouncedCallback = debounce(callback, 100, { maxWait: 200 });
+    debouncedCallback();
+    expect(callback).not.toHaveBeenCalled();
+
+    vi.advanceTimersByTime(10);
+    expect(callback).not.toHaveBeenCalled();
+
+    debouncedCallback.flush();
+    expect(callback).toHaveBeenCalled();
+  });
+
+  it('should not invoke the callback, if  callback.cancel() is called', () => {
+    const callback = vi.fn();
+    const debouncedCallback = debounce(callback, 100, { maxWait: 200 });
+    debouncedCallback();
+    expect(callback).not.toHaveBeenCalled();
+
+    vi.advanceTimersByTime(99);
+    expect(callback).not.toHaveBeenCalled();
+
+    // If the callback is canceled, it should not be invoked after the minwait
+    debouncedCallback.cancel();
+    vi.advanceTimersByTime(1);
+    expect(callback).not.toHaveBeenCalled();
+
+    // And it should also not be invoked after the maxWait
+    vi.advanceTimersByTime(500);
+    expect(callback).not.toHaveBeenCalled();
+  });
+
+  it("should return the callback's return value when calling callback.flush()", () => {
+    const callback = vi.fn().mockReturnValue('foo');
+    const debouncedCallback = debounce(callback, 100);
+
+    debouncedCallback();
+
+    const returnValue = debouncedCallback.flush();
+    expect(returnValue).toBe('foo');
+  });
+
+  it('should return the callbacks return value on subsequent calls of the debounced function', () => {
+    const callback = vi.fn().mockReturnValue('foo');
+    const debouncedCallback = debounce(callback, 100);
+
+    const returnValue1 = debouncedCallback();
+    expect(returnValue1).toBe(undefined);
+    expect(callback).not.toHaveBeenCalled();
+
+    // now we expect the callback to have been invoked
+    vi.advanceTimersByTime(200);
+    expect(callback).toHaveBeenCalledTimes(1);
+
+    // calling the debounced function now should return the return value of the callback execution
+    const returnValue2 = debouncedCallback();
+    expect(returnValue2).toBe('foo');
+    expect(callback).toHaveBeenCalledTimes(1);
+
+    // and the callback should also be invoked again
+    vi.advanceTimersByTime(200);
+    expect(callback).toHaveBeenCalledTimes(2);
+  });
+
+  it('should handle return values of consecutive invocations without maxWait', () => {
+    let i = 0;
+    const callback = vi.fn().mockImplementation(() => {
+      return `foo-${++i}`;
+    });
+    const debouncedCallback = debounce(callback, 100);
+
+    const returnValue0 = debouncedCallback();
+    expect(returnValue0).toBe(undefined);
+    expect(callback).not.toHaveBeenCalled();
+
+    // now we expect the callback to have been invoked
+    vi.advanceTimersByTime(200);
+    expect(callback).toHaveBeenCalledTimes(1);
+
+    // calling the debounced function now should return the return value of the callback execution
+    const returnValue1 = debouncedCallback();
+    expect(returnValue1).toBe('foo-1');
+    expect(callback).toHaveBeenCalledTimes(1);
+
+    vi.advanceTimersByTime(1);
+    const returnValue2 = debouncedCallback();
+    expect(returnValue2).toBe('foo-1');
+    expect(callback).toHaveBeenCalledTimes(1);
+
+    // and the callback should also be invoked again
+    vi.advanceTimersByTime(200);
+    const returnValue3 = debouncedCallback();
+    expect(returnValue3).toBe('foo-2');
+    expect(callback).toHaveBeenCalledTimes(2);
+  });
+
+  it('should handle return values of consecutive invocations with maxWait', () => {
+    let i = 0;
+    const callback = vi.fn().mockImplementation(() => {
+      return `foo-${++i}`;
+    });
+    const debouncedCallback = debounce(callback, 150, { maxWait: 200 });
+
+    const returnValue0 = debouncedCallback();
+    expect(returnValue0).toBe(undefined);
+    expect(callback).not.toHaveBeenCalled();
+
+    // now we expect the callback to have been invoked
+    vi.advanceTimersByTime(149);
+    const returnValue1 = debouncedCallback();
+    expect(returnValue1).toBe(undefined);
+    expect(callback).not.toHaveBeenCalled();
+
+    // calling the debounced function now should return the return value of the callback execution
+    // as it was executed because of maxWait
+    vi.advanceTimersByTime(51);
+    const returnValue2 = debouncedCallback();
+    expect(returnValue2).toBe('foo-1');
+    expect(callback).toHaveBeenCalledTimes(1);
+
+    // at this point (100ms after the last debounce call), nothing should have happened
+    vi.advanceTimersByTime(100);
+    const returnValue3 = debouncedCallback();
+    expect(returnValue3).toBe('foo-1');
+    expect(callback).toHaveBeenCalledTimes(1);
+
+    // and the callback should now have been invoked again
+    vi.advanceTimersByTime(150);
+    const returnValue4 = debouncedCallback();
+    expect(returnValue4).toBe('foo-2');
+    expect(callback).toHaveBeenCalledTimes(2);
+  });
+
+  it('should handle return values of consecutive invocations after a cancellation', () => {
+    let i = 0;
+    const callback = vi.fn().mockImplementation(() => {
+      return `foo-${++i}`;
+    });
+    const debouncedCallback = debounce(callback, 150, { maxWait: 200 });
+
+    const returnValue0 = debouncedCallback();
+    expect(returnValue0).toBe(undefined);
+    expect(callback).not.toHaveBeenCalled();
+
+    // now we expect the callback to have been invoked
+    vi.advanceTimersByTime(149);
+    const returnValue1 = debouncedCallback();
+    expect(returnValue1).toBe(undefined);
+    expect(callback).not.toHaveBeenCalled();
+
+    debouncedCallback.cancel();
+
+    // calling the debounced function now still return undefined because we cancelled the invocation
+    vi.advanceTimersByTime(51);
+    const returnValue2 = debouncedCallback();
+    expect(returnValue2).toBe(undefined);
+    expect(callback).not.toHaveBeenCalled();
+
+    // and the callback should also be invoked again
+    vi.advanceTimersByTime(150);
+    const returnValue3 = debouncedCallback();
+    expect(returnValue3).toBe('foo-1');
+    expect(callback).toHaveBeenCalledTimes(1);
+  });
+
+  it('should handle the return value of calling flush after cancelling', () => {
+    const callback = vi.fn().mockReturnValue('foo');
+    const debouncedCallback = debounce(callback, 100);
+
+    debouncedCallback();
+    debouncedCallback.cancel();
+
+    const returnValue = debouncedCallback.flush();
+    expect(returnValue).toBe(undefined);
+  });
+
+  it('should handle equal wait and maxWait values and only invoke func once', () => {
+    const callback = vi.fn().mockReturnValue('foo');
+    const debouncedCallback = debounce(callback, 100, { maxWait: 100 });
+
+    debouncedCallback();
+    vi.advanceTimersByTime(25);
+    debouncedCallback();
+    vi.advanceTimersByTime(25);
+    debouncedCallback();
+    vi.advanceTimersByTime(25);
+    debouncedCallback();
+    vi.advanceTimersByTime(25);
+
+    expect(callback).toHaveBeenCalledTimes(1);
+
+    const retval = debouncedCallback();
+    expect(retval).toBe('foo');
+
+    vi.advanceTimersByTime(25);
+    debouncedCallback();
+    vi.advanceTimersByTime(25);
+    debouncedCallback();
+    vi.advanceTimersByTime(25);
+    debouncedCallback();
+    vi.advanceTimersByTime(25);
+
+    expect(callback).toHaveBeenCalledTimes(2);
+  });
+});