Skip to content

Commit

Permalink
Exponentially backs off retry attempts for sending usage data (elasti…
Browse files Browse the repository at this point in the history 
…c#117955)
  • Loading branch information
@TinaHeiligers @kpatticha
TinaHeiligers authored and kpatticha committed Nov 10, 2021
1 parent f85d63a commit 92d07cb
Show file tree
Hide file tree
Showing 2 changed files with 214 additions and 115 deletions.
292 changes: 188 additions & 104 deletions src/plugins/telemetry/public/services/telemetry_sender.test.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -127,67 +127,111 @@ describe('TelemetrySender', () => {
expect(telemetryService.getIsOptedIn).toBeCalledTimes(0);
expect(shouldSendReport).toBe(false);
});
});
describe('sendIfDue', () => {
let originalFetch: typeof window['fetch'];
let mockFetch: jest.Mock<typeof window['fetch']>;

describe('sendIfDue', () => {
let originalFetch: typeof window['fetch'];
let mockFetch: jest.Mock<typeof window['fetch']>;
beforeAll(() => {
originalFetch = window.fetch;
});

beforeAll(() => {
originalFetch = window.fetch;
});
beforeEach(() => (window.fetch = mockFetch = jest.fn()));
afterAll(() => (window.fetch = originalFetch));

beforeEach(() => (window.fetch = mockFetch = jest.fn()));
afterAll(() => (window.fetch = originalFetch));
it('does not send if shouldSendReport returns false', async () => {
const telemetryService = mockTelemetryService();
const telemetrySender = new TelemetrySender(telemetryService);
telemetrySender['shouldSendReport'] = jest.fn().mockReturnValue(false);
telemetrySender['retryCount'] = 0;
await telemetrySender['sendIfDue']();

it('does not send if already sending', async () => {
const telemetryService = mockTelemetryService();
const telemetrySender = new TelemetrySender(telemetryService);
telemetrySender['shouldSendReport'] = jest.fn();
telemetrySender['isSending'] = true;
await telemetrySender['sendIfDue']();
expect(telemetrySender['shouldSendReport']).toBeCalledTimes(1);
expect(mockFetch).toBeCalledTimes(0);
});

expect(telemetrySender['shouldSendReport']).toBeCalledTimes(0);
expect(mockFetch).toBeCalledTimes(0);
});
it('does not send if we are in screenshot mode', async () => {
const telemetryService = mockTelemetryService({ isScreenshotMode: true });
const telemetrySender = new TelemetrySender(telemetryService);
await telemetrySender['sendIfDue']();

it('does not send if shouldSendReport returns false', async () => {
const telemetryService = mockTelemetryService();
const telemetrySender = new TelemetrySender(telemetryService);
telemetrySender['shouldSendReport'] = jest.fn().mockReturnValue(false);
telemetrySender['isSending'] = false;
await telemetrySender['sendIfDue']();
expect(mockFetch).toBeCalledTimes(0);
});

expect(telemetrySender['shouldSendReport']).toBeCalledTimes(1);
expect(mockFetch).toBeCalledTimes(0);
});
it('updates last lastReported and calls saveToBrowser', async () => {
const lastReported = Date.now() - (REPORT_INTERVAL_MS + 1000);

const telemetryService = mockTelemetryService();
const telemetrySender = new TelemetrySender(telemetryService);
telemetrySender['shouldSendReport'] = jest.fn().mockReturnValue(true);
telemetrySender['sendUsageData'] = jest.fn().mockReturnValue(true);
telemetrySender['saveToBrowser'] = jest.fn();
telemetrySender['lastReported'] = `${lastReported}`;

it('does not send if we are in screenshot mode', async () => {
const telemetryService = mockTelemetryService({ isScreenshotMode: true });
const telemetrySender = new TelemetrySender(telemetryService);
telemetrySender['isSending'] = false;
await telemetrySender['sendIfDue']();
await telemetrySender['sendIfDue']();

expect(mockFetch).toBeCalledTimes(0);
});
expect(telemetrySender['lastReported']).not.toBe(lastReported);
expect(telemetrySender['saveToBrowser']).toBeCalledTimes(1);
expect(telemetrySender['retryCount']).toEqual(0);
expect(telemetrySender['sendUsageData']).toHaveBeenCalledTimes(1);
});

it('resets the retry counter when report is due', async () => {
const telemetryService = mockTelemetryService();
const telemetrySender = new TelemetrySender(telemetryService);
telemetrySender['shouldSendReport'] = jest.fn().mockReturnValue(true);
telemetrySender['sendUsageData'] = jest.fn();
telemetrySender['saveToBrowser'] = jest.fn();
telemetrySender['retryCount'] = 9;

await telemetrySender['sendIfDue']();
expect(telemetrySender['retryCount']).toEqual(0);
expect(telemetrySender['sendUsageData']).toHaveBeenCalledTimes(1);
});
});

describe('sendUsageData', () => {
let originalFetch: typeof window['fetch'];
let mockFetch: jest.Mock<typeof window['fetch']>;
let consoleWarnMock: jest.SpyInstance;

beforeAll(() => {
originalFetch = window.fetch;
});

it('sends report if due', async () => {
const mockClusterUuid = 'mk_uuid';
const mockTelemetryUrl = 'telemetry_cluster_url';
const mockTelemetryPayload = [
{ clusterUuid: mockClusterUuid, stats: 'hashed_cluster_usage_data1' },
];

const telemetryService = mockTelemetryService();
const telemetrySender = new TelemetrySender(telemetryService);
telemetryService.getTelemetryUrl = jest.fn().mockReturnValue(mockTelemetryUrl);
telemetryService.fetchTelemetry = jest.fn().mockReturnValue(mockTelemetryPayload);
telemetrySender['shouldSendReport'] = jest.fn().mockReturnValue(true);
telemetrySender['isSending'] = false;
await telemetrySender['sendIfDue']();

expect(telemetryService.fetchTelemetry).toBeCalledTimes(1);
expect(mockFetch).toBeCalledTimes(1);
expect(mockFetch.mock.calls[0]).toMatchInlineSnapshot(`
beforeEach(() => {
window.fetch = mockFetch = jest.fn();
jest.useFakeTimers();
consoleWarnMock = jest.spyOn(global.console, 'warn').mockImplementation(() => {});
});

afterEach(() => {
jest.resetAllMocks();
});

afterAll(() => {
window.fetch = originalFetch;
jest.useRealTimers();
});

it('sends the report', async () => {
const mockClusterUuid = 'mk_uuid';
const mockTelemetryUrl = 'telemetry_cluster_url';
const mockTelemetryPayload = [
{ clusterUuid: mockClusterUuid, stats: 'hashed_cluster_usage_data1' },
];

const telemetryService = mockTelemetryService();
const telemetrySender = new TelemetrySender(telemetryService);
telemetryService.getTelemetryUrl = jest.fn().mockReturnValue(mockTelemetryUrl);
telemetryService.fetchTelemetry = jest.fn().mockReturnValue(mockTelemetryPayload);
telemetrySender['shouldSendReport'] = jest.fn().mockReturnValue(true);

await telemetrySender['sendUsageData']();

expect(telemetryService.fetchTelemetry).toBeCalledTimes(1);
expect(mockFetch).toBeCalledTimes(1);
expect(mockFetch.mock.calls[0]).toMatchInlineSnapshot(`
Array [
"telemetry_cluster_url",
Object {
Expand All @@ -202,73 +246,113 @@ describe('TelemetrySender', () => {
},
]
`);
});
});

it('sends report separately for every cluster', async () => {
const mockTelemetryUrl = 'telemetry_cluster_url';
const mockTelemetryPayload = ['hashed_cluster_usage_data1', 'hashed_cluster_usage_data2'];
it('sends report separately for every cluster', async () => {
const mockTelemetryUrl = 'telemetry_cluster_url';
const mockTelemetryPayload = ['hashed_cluster_usage_data1', 'hashed_cluster_usage_data2'];

const telemetryService = mockTelemetryService();
const telemetrySender = new TelemetrySender(telemetryService);
telemetryService.getTelemetryUrl = jest.fn().mockReturnValue(mockTelemetryUrl);
telemetryService.fetchTelemetry = jest.fn().mockReturnValue(mockTelemetryPayload);
telemetrySender['shouldSendReport'] = jest.fn().mockReturnValue(true);
telemetrySender['isSending'] = false;
await telemetrySender['sendIfDue']();
const telemetryService = mockTelemetryService();
const telemetrySender = new TelemetrySender(telemetryService);
telemetryService.getTelemetryUrl = jest.fn().mockReturnValue(mockTelemetryUrl);
telemetryService.fetchTelemetry = jest.fn().mockReturnValue(mockTelemetryPayload);
telemetrySender['shouldSendReport'] = jest.fn().mockReturnValue(true);
await telemetrySender['sendIfDue']();

expect(telemetryService.fetchTelemetry).toBeCalledTimes(1);
expect(mockFetch).toBeCalledTimes(2);
});
expect(telemetryService.fetchTelemetry).toBeCalledTimes(1);
expect(mockFetch).toBeCalledTimes(2);
});

it('updates last lastReported and calls saveToBrowser', async () => {
const mockTelemetryUrl = 'telemetry_cluster_url';
const mockTelemetryPayload = ['hashed_cluster_usage_data1'];
it('does not increase the retry counter on successful send', async () => {
const mockTelemetryUrl = 'telemetry_cluster_url';
const mockTelemetryPayload = ['hashed_cluster_usage_data1'];

const telemetryService = mockTelemetryService();
const telemetrySender = new TelemetrySender(telemetryService);
telemetryService.getTelemetryUrl = jest.fn().mockReturnValue(mockTelemetryUrl);
telemetryService.fetchTelemetry = jest.fn().mockReturnValue(mockTelemetryPayload);
telemetrySender['shouldSendReport'] = jest.fn().mockReturnValue(true);
telemetrySender['saveToBrowser'] = jest.fn();
const telemetryService = mockTelemetryService();
const telemetrySender = new TelemetrySender(telemetryService);
telemetryService.getTelemetryUrl = jest.fn().mockReturnValue(mockTelemetryUrl);
telemetryService.fetchTelemetry = jest.fn().mockReturnValue(mockTelemetryPayload);
telemetrySender['shouldSendReport'] = jest.fn().mockReturnValue(true);
telemetrySender['saveToBrowser'] = jest.fn();

await telemetrySender['sendIfDue']();
await telemetrySender['sendUsageData']();

expect(mockFetch).toBeCalledTimes(1);
expect(telemetrySender['retryCount']).toBe(0);
});

expect(mockFetch).toBeCalledTimes(1);
expect(telemetrySender['lastReported']).toBeDefined();
expect(telemetrySender['saveToBrowser']).toBeCalledTimes(1);
expect(telemetrySender['isSending']).toBe(false);
it('catches fetchTelemetry errors and retries again', async () => {
const telemetryService = mockTelemetryService();
const telemetrySender = new TelemetrySender(telemetryService);
telemetryService.getTelemetryUrl = jest.fn();
telemetryService.fetchTelemetry = jest.fn().mockImplementation(() => {
throw Error('Error fetching usage');
});
await telemetrySender['sendUsageData']();
expect(telemetryService.fetchTelemetry).toBeCalledTimes(1);
expect(telemetrySender['retryCount']).toBe(1);
expect(setTimeout).toBeCalledTimes(1);
expect(setTimeout).toBeCalledWith(telemetrySender['sendUsageData'], 120000);
expect(consoleWarnMock).not.toBeCalled(); // console.warn is only triggered when the retryCount exceeds the allowed number
});

it('catches fetchTelemetry errors and sets isSending to false', async () => {
const telemetryService = mockTelemetryService();
const telemetrySender = new TelemetrySender(telemetryService);
telemetryService.getTelemetryUrl = jest.fn();
telemetryService.fetchTelemetry = jest.fn().mockImplementation(() => {
throw Error('Error fetching usage');
});
await telemetrySender['sendIfDue']();
expect(telemetryService.fetchTelemetry).toBeCalledTimes(1);
expect(telemetrySender['lastReported']).toBeUndefined();
expect(telemetrySender['isSending']).toBe(false);
it('catches fetch errors and sets a new timeout if fetch fails more than once', async () => {
const mockTelemetryPayload = ['hashed_cluster_usage_data1', 'hashed_cluster_usage_data2'];
const telemetryService = mockTelemetryService();
const telemetrySender = new TelemetrySender(telemetryService);
telemetryService.getTelemetryUrl = jest.fn();
telemetryService.fetchTelemetry = jest.fn().mockReturnValue(mockTelemetryPayload);
mockFetch.mockImplementation(() => {
throw Error('Error sending usage');
});
telemetrySender['retryCount'] = 3;
await telemetrySender['sendUsageData']();

expect(telemetryService.fetchTelemetry).toBeCalledTimes(1);
expect(mockFetch).toBeCalledTimes(2);
expect(telemetrySender['retryCount']).toBe(4);
expect(setTimeout).toBeCalledWith(telemetrySender['sendUsageData'], 960000);

await telemetrySender['sendUsageData']();
expect(telemetrySender['retryCount']).toBe(5);
expect(setTimeout).toBeCalledWith(telemetrySender['sendUsageData'], 1920000);
expect(consoleWarnMock).not.toBeCalled(); // console.warn is only triggered when the retryCount exceeds the allowed number
});

it('catches fetch errors and sets isSending to false', async () => {
const mockTelemetryPayload = ['hashed_cluster_usage_data1', 'hashed_cluster_usage_data2'];
const telemetryService = mockTelemetryService();
const telemetrySender = new TelemetrySender(telemetryService);
telemetryService.getTelemetryUrl = jest.fn();
telemetryService.fetchTelemetry = jest.fn().mockReturnValue(mockTelemetryPayload);
mockFetch.mockImplementation(() => {
throw Error('Error sending usage');
});
await telemetrySender['sendIfDue']();
expect(telemetryService.fetchTelemetry).toBeCalledTimes(1);
expect(mockFetch).toBeCalledTimes(2);
expect(telemetrySender['lastReported']).toBeUndefined();
expect(telemetrySender['isSending']).toBe(false);
it('stops trying to resend the data after 20 retries', async () => {
const telemetryService = mockTelemetryService();
const telemetrySender = new TelemetrySender(telemetryService);
telemetryService.getTelemetryUrl = jest.fn();
telemetryService.fetchTelemetry = jest.fn().mockImplementation(() => {
throw Error('Error fetching usage');
});
telemetrySender['retryCount'] = 21;
await telemetrySender['sendUsageData']();
expect(setTimeout).not.toBeCalled();
expect(consoleWarnMock.mock.calls[0][0]).toBe(
'TelemetrySender.sendUsageData exceeds number of retry attempts with Error fetching usage'
);
});
});

describe('getRetryDelay', () => {
beforeEach(() => jest.useFakeTimers());
afterAll(() => jest.useRealTimers());

it('sets a minimum retry delay of 60 seconds', () => {
expect(TelemetrySender.getRetryDelay(0)).toBe(60000);
});

it('changes the retry delay depending on the retry count', () => {
expect(TelemetrySender.getRetryDelay(3)).toBe(480000);
expect(TelemetrySender.getRetryDelay(5)).toBe(1920000);
});

it('sets a maximum retry delay of 64 min', () => {
expect(TelemetrySender.getRetryDelay(8)).toBe(3840000);
expect(TelemetrySender.getRetryDelay(10)).toBe(3840000);
});
});

describe('startChecking', () => {
beforeEach(() => jest.useFakeTimers());
afterAll(() => jest.useRealTimers());
Expand Down
37 changes: 26 additions & 11 deletions src/plugins/telemetry/public/services/telemetry_sender.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -17,10 +17,14 @@ import type { EncryptedTelemetryPayload } from '../../common/types';

export class TelemetrySender {
private readonly telemetryService: TelemetryService;
private isSending: boolean = false;
private lastReported?: string;
private readonly storage: Storage;
private intervalId?: number;
private intervalId: number = 0; // setInterval returns a positive integer, 0 means no interval is set
private retryCount: number = 0;

static getRetryDelay(retryCount: number) {
return 60 * (1000 * Math.min(Math.pow(2, retryCount), 64)); // 120s, 240s, 480s, 960s, 1920s, 3840s, 3840s, 3840s
}

constructor(telemetryService: TelemetryService) {
this.telemetryService = telemetryService;
Expand Down Expand Up @@ -54,12 +58,17 @@ export class TelemetrySender {
};

private sendIfDue = async (): Promise<void> => {
if (this.isSending || !this.shouldSendReport()) {
if (!this.shouldSendReport()) {
return;
}
// optimistically update the report date and reset the retry counter for a new time report interval window
this.lastReported = `${Date.now()}`;
this.saveToBrowser();
this.retryCount = 0;
await this.sendUsageData();
};

// mark that we are working so future requests are ignored until we're done
this.isSending = true;
private sendUsageData = async (): Promise<void> => {
try {
const telemetryUrl = this.telemetryService.getTelemetryUrl();
const telemetryPayload: EncryptedTelemetryPayload =
Expand All @@ -80,17 +89,23 @@ export class TelemetrySender {
})
)
);
this.lastReported = `${Date.now()}`;
this.saveToBrowser();
} catch (err) {
// ignore err
} finally {
this.isSending = false;
// ignore err and try again but after a longer wait period.
this.retryCount = this.retryCount + 1;
if (this.retryCount < 20) {
// exponentially backoff the time between subsequent retries to up to 19 attempts, after which we give up until the next report is due
window.setTimeout(this.sendUsageData, TelemetrySender.getRetryDelay(this.retryCount));
} else {
/* eslint no-console: ["error", { allow: ["warn"] }] */
console.warn(
`TelemetrySender.sendUsageData exceeds number of retry attempts with ${err.message}`
);
}
}
};

public startChecking = () => {
if (typeof this.intervalId === 'undefined') {
if (this.intervalId === 0) {
this.intervalId = window.setInterval(this.sendIfDue, 60000);
}
};
Expand Down

0 comments on commit 92d07cb

Please sign in to comment.