Skip to content

Commit 63515d4

Browse files
authored
[Response Ops][Reporting] Fixing error in calculating delay value between retries (elastic#245431)
## Summary It was pointed out that there's an error in calculating the delay between retries for scheduled reporting tasks.
1 parent ca390cf commit 63515d4

File tree

2 files changed

+63
-13
lines changed

2 files changed

+63
-13
lines changed

x-pack/platform/plugins/private/reporting/server/lib/retry_on_error.test.ts

Lines changed: 61 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -29,14 +29,16 @@ const report = new SavedReport({
2929

3030
describe('retryOnError', () => {
3131
beforeEach(() => {
32-
jest.resetAllMocks();
32+
jest.clearAllMocks();
33+
jest.useFakeTimers();
34+
jest.spyOn(global, 'setTimeout');
3335
jest.spyOn(global.Math, 'random').mockReturnValue(randomDelayMultiplier);
3436
});
3537

3638
afterEach(() => {
37-
jest.restoreAllMocks();
39+
jest.clearAllTimers();
40+
jest.useRealTimers();
3841
});
39-
4042
it(`doesn't retry if operation is successful`, async () => {
4143
const operationMock = jest.fn().mockResolvedValue('success');
4244
expect(await retryOnError({ operation: operationMock, retries: 3, report, logger })).toEqual(
@@ -47,13 +49,24 @@ describe('retryOnError', () => {
4749
expect(logger.info).not.toHaveBeenCalled();
4850
expect(logger.warn).not.toHaveBeenCalled();
4951
expect(logger.error).not.toHaveBeenCalled();
52+
expect(setTimeout).not.toHaveBeenCalled();
5053
});
5154

5255
it('logs an error message on retry', async () => {
5356
const error = new Error('fail');
5457
const operationMock = jest.fn().mockRejectedValueOnce(error).mockResolvedValue('success');
5558

56-
await retryOnError({ operation: operationMock, retries: 3, report, logger });
59+
const retryPromise = retryOnError({ operation: operationMock, retries: 3, report, logger });
60+
await Promise.resolve();
61+
62+
jest.runAllTimers();
63+
await retryPromise;
64+
65+
expect(setTimeout).toHaveBeenCalledTimes(1);
66+
expect(setTimeout).toHaveBeenCalledWith(
67+
expect.any(Function),
68+
2000 * (1 + randomDelayMultiplier)
69+
);
5770
expect(logger.error).toHaveBeenCalledTimes(1);
5871
expect(logger.error.mock.calls[0][0]).toEqual(
5972
`Retrying report generation for report[${
@@ -78,6 +91,7 @@ describe('retryOnError', () => {
7891
expect(logger.info).not.toHaveBeenCalled();
7992
expect(logger.warn).not.toHaveBeenCalled();
8093
expect(logger.error).not.toHaveBeenCalled();
94+
expect(setTimeout).not.toHaveBeenCalled();
8195
expect(operationMock).toHaveBeenCalledTimes(1);
8296
});
8397

@@ -93,6 +107,7 @@ describe('retryOnError', () => {
93107
expect(logger.info).not.toHaveBeenCalled();
94108
expect(logger.warn).not.toHaveBeenCalled();
95109
expect(logger.error).not.toHaveBeenCalled();
110+
expect(setTimeout).not.toHaveBeenCalled();
96111
expect(operationMock).toHaveBeenCalledTimes(1);
97112
});
98113

@@ -105,10 +120,28 @@ describe('retryOnError', () => {
105120
.mockRejectedValueOnce(error)
106121
.mockResolvedValue('success');
107122

108-
expect(await retryOnError({ operation: operationMock, retries: 3, report, logger })).toEqual(
109-
'success'
110-
);
123+
const retryPromise = retryOnError({ operation: operationMock, retries: 3, report, logger });
124+
await Promise.resolve();
125+
126+
jest.runAllTimersAsync().catch(() => {});
127+
expect(await retryPromise).toEqual('success');
111128
// initial attempt + 3 retries
129+
expect(setTimeout).toHaveBeenCalledTimes(3);
130+
expect(setTimeout).toHaveBeenNthCalledWith(
131+
1,
132+
expect.any(Function),
133+
2000 * (1 + randomDelayMultiplier)
134+
);
135+
expect(setTimeout).toHaveBeenNthCalledWith(
136+
2,
137+
expect.any(Function),
138+
4000 * (1 + randomDelayMultiplier)
139+
);
140+
expect(setTimeout).toHaveBeenNthCalledWith(
141+
3,
142+
expect.any(Function),
143+
8000 * (1 + randomDelayMultiplier)
144+
);
112145
expect(operationMock).toHaveBeenCalledTimes(4);
113146
expect(logger.error).toHaveBeenCalledTimes(3);
114147
expect(logger.error.mock.calls[0][0]).toEqual(
@@ -136,14 +169,30 @@ describe('retryOnError', () => {
136169
const error = new Error('fail');
137170
const operationMock = jest.fn().mockRejectedValue(error);
138171

139-
await expect(
140-
retryOnError({ operation: operationMock, retries: 3, report, logger })
141-
).rejects.toThrowErrorMatchingInlineSnapshot(`"fail"`);
142-
expect(logger.error).toHaveBeenCalledTimes(3);
172+
const retryPromise = retryOnError({ operation: operationMock, retries: 3, report, logger });
173+
await Promise.resolve();
174+
175+
jest.runAllTimersAsync().catch(() => {});
176+
await expect(retryPromise).rejects.toThrowErrorMatchingInlineSnapshot(`"fail"`);
143177

144178
// initial attempt + 3 retries
145179
expect(operationMock).toHaveBeenCalledTimes(4);
146-
180+
expect(setTimeout).toHaveBeenCalledTimes(3);
181+
expect(setTimeout).toHaveBeenNthCalledWith(
182+
1,
183+
expect.any(Function),
184+
2000 * (1 + randomDelayMultiplier)
185+
);
186+
expect(setTimeout).toHaveBeenNthCalledWith(
187+
2,
188+
expect.any(Function),
189+
4000 * (1 + randomDelayMultiplier)
190+
);
191+
expect(setTimeout).toHaveBeenNthCalledWith(
192+
3,
193+
expect.any(Function),
194+
8000 * (1 + randomDelayMultiplier)
195+
);
147196
expect(logger.error.mock.calls[0][0]).toEqual(
148197
`Retrying report generation for report[${
149198
report._id

x-pack/platform/plugins/private/reporting/server/lib/retry_on_error.ts

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -58,7 +58,8 @@ export const retryOnError = async ({
5858
);
5959

6060
// delay with some randomness
61-
await delay(retryDelaySec + 1000 * Math.random());
61+
// convert delay to milliseconds and multiply by random number between 1.0 and 2.0
62+
await delay(retryDelaySec * 1000 * (1 + Math.random()));
6263
return retryOnError({ operation, logger, report, retries, attempt: retryCount });
6364
}
6465

0 commit comments

Comments
 (0)