implements backoff delay in usage counters service

src/platform/plugins/shared/usage_collection/server/usage_counters/usage_counters_service.test.ts

@@ -25,9 +25,10 @@ const registerUsageCountersRollupsMock = registerUsageCountersRollups as jest.Mo
   typeof registerUsageCountersRollups
 >;
 
-const tick = () => {
+// optionally advance test timers after a delay
+const tickWithDelay = (delay = 1) => {
   jest.useRealTimers();
-  return new Promise((resolve) => setTimeout(resolve, 1));
+  return new Promise((resolve) => setTimeout(resolve, delay));
 };
 
 describe('UsageCountersService', () => {
@@ -190,14 +191,15 @@ describe('UsageCountersService', () => {
   });
 
   it('retries errors by `retryCount` times before failing to store', async () => {
+    const retryConst = 2;
     const usageCountersService = new UsageCountersService({
       logger,
-      retryCount: 1,
+      retryCount: retryConst,
       bufferDurationMs,
     });
 
     const mockRepository = coreStart.savedObjects.createInternalRepository();
-    const mockError = new Error('failed.');
+    const mockError = new Error('failed');
     const mockIncrementCounter = jest.fn().mockImplementation((_, key) => {
       switch (key) {
         case 'test-counter:counterA:count:server:20210409':
@@ -222,9 +224,11 @@ describe('UsageCountersService', () => {
     jest.runOnlyPendingTimers();
 
     // wait for retries to kick in on next scheduler call
-    await tick();
+    await tickWithDelay(80); // check retry up to 2 times
     // number of incrementCounter calls + number of retries
-    expect(mockIncrementCounter).toBeCalledTimes(2 + 1);
+    expect(mockIncrementCounter).toBeCalledTimes(2 + retryConst);
+    expect(logger.warn).toHaveBeenNthCalledWith(1, `${mockError}, retrying attempt ${retryConst}`); // assert counterA increment error warning log
+    expect(logger.warn).toHaveBeenNthCalledWith(3, mockError); // reassert counterA increment error warning log
     expect(logger.debug).toHaveBeenNthCalledWith(1, 'Store counters into savedObjects', {
       kibana: {
         usageCounters: {
@@ -264,7 +268,7 @@ describe('UsageCountersService', () => {
     jest.runOnlyPendingTimers();
 
     // wait for debounce to kick in on next scheduler call
-    await tick();
+    await tickWithDelay();
     expect(mockIncrementCounter).toBeCalledTimes(2);
     expect(mockIncrementCounter.mock.results.map(({ value }) => value)).toMatchInlineSnapshot(`
       Array [

src/platform/plugins/shared/usage_collection/server/usage_counters/usage_counters_service.ts

@@ -159,14 +159,22 @@ export class UsageCountersService {
     };
   };
 
+  private backoffDelay = (attempt: number) => Math.pow(2, attempt) * 10; // exponential backoff: 20ms, 40ms, 80ms, 150ms etc
+
   private storeDate$(
     counters: UsageCounters.v1.CounterMetric[],
     soRepository: Pick<SavedObjectsRepository, 'incrementCounter'>
   ) {
     return Rx.forkJoin(
       counters.map((metric) =>
         Rx.defer(() => storeCounter({ metric, soRepository })).pipe(
-          Rx.retry(this.retryCount),
+          Rx.retry({
+            count: this.retryCount,
+            delay: (error, retryIndex) => {
+              this.logger.warn(`Error: ${error.message}, retrying attempt ${retryIndex + 1}`); // extra warning logger
+              return Rx.timer(this.backoffDelay(retryIndex));
+            },
+          }),
           Rx.catchError((error) => {
             this.logger.warn(error);
             return Rx.of(error);