From 878f8c9b281e3ea943a07f2a2c3f974398537178 Mon Sep 17 00:00:00 2001 From: Rhys Date: Tue, 17 May 2022 11:28:00 +0100 Subject: [PATCH] feat(search-index): add retry for search index create and settings update --- .../__snapshots__/import.spec.ts.snap | 2 + src/commands/search-index/import.spec.ts | 158 ++++++++++++++++- src/commands/search-index/import.ts | 43 ++++- .../content-item/__mocks__/retry-helpers.ts | 27 +++ src/common/content-item/retry-helpers.spec.ts | 159 ++++++++++++++++++ src/common/content-item/retry-helpers.ts | 54 ++++++ 6 files changed, 429 insertions(+), 14 deletions(-) create mode 100644 src/common/content-item/__mocks__/retry-helpers.ts create mode 100644 src/common/content-item/retry-helpers.spec.ts create mode 100644 src/common/content-item/retry-helpers.ts diff --git a/src/commands/search-index/__snapshots__/import.spec.ts.snap b/src/commands/search-index/__snapshots__/import.spec.ts.snap index 2499de56..f67d53ec 100644 --- a/src/commands/search-index/__snapshots__/import.spec.ts.snap +++ b/src/commands/search-index/__snapshots__/import.spec.ts.snap @@ -1,5 +1,7 @@ // Jest Snapshot v1, https://goo.gl/fbAQLP +exports[`search-index import command doCreate should error if the index never appears after a 504 1`] = `"Error creating index index-name: Error: waitOnTimeout"`; + exports[`search-index import command doCreate should throw an error when enrichIndex fails 1`] = `"Error creating index index-name: The update-index action is not available, ensure you have permission to perform this action."`; exports[`search-index import command doCreate should throw an error when index create fails 1`] = `"Error creating index index-name: Error: Error creating index"`; diff --git a/src/commands/search-index/import.spec.ts b/src/commands/search-index/import.spec.ts index c9442ca7..de599f5d 100644 --- a/src/commands/search-index/import.spec.ts +++ b/src/commands/search-index/import.spec.ts @@ -1,8 +1,9 @@ import dynamicContentClientFactory from '../../services/dynamic-content-client-factory'; -import { SearchIndex, Hub, Webhook, SearchIndexSettings } from 'dc-management-sdk-js'; +import { SearchIndex, Hub, Webhook, SearchIndexSettings, HttpError } from 'dc-management-sdk-js'; import * as exportModule from './export'; import * as importModule from './import'; import * as webhookRewriter from './webhook-rewriter'; +import * as retryHelpers from '../../common/content-item/retry-helpers'; import { builder, command, @@ -35,6 +36,13 @@ jest.mock('../../services/import.service'); jest.mock('fs'); jest.mock('table'); jest.mock('../../common/log-helpers'); +jest.mock('../../common/content-item/retry-helpers'); + +// eslint-disable-next-line @typescript-eslint/no-explicit-any +const setTestCheck = (retryHelpers as any).setTestCheck; + +// eslint-disable-next-line @typescript-eslint/no-explicit-any +const error504 = new HttpError('Error', undefined, { status: 504 } as any); describe('search-index import command', (): void => { afterEach((): void => { @@ -159,6 +167,10 @@ describe('search-index import command', (): void => { const assignedContentType = new AssignedContentType({ contentTypeUri: 'http://uri.com' }); const assignedContentTypes = [{ contentTypeUri: 'http://uri.com' }]; + afterEach(() => { + setTestCheck(false); + }); + it('should create an index and return report', async () => { const mockHub = new Hub(); const log = new FileLog(); @@ -177,7 +189,7 @@ describe('search-index import command', (): void => { ] `); expect(mockCreate).toHaveBeenCalledWith(expect.objectContaining({ ...indexBase, assignedContentTypes })); - expect(importModule.enrichIndex).toHaveBeenCalledWith(mockHub, newIndex, index, webhooks); + expect(importModule.enrichIndex).toHaveBeenCalledWith(mockHub, newIndex, index, webhooks, log); expect(result).toEqual(newIndex); }); @@ -237,7 +249,64 @@ describe('search-index import command', (): void => { ).rejects.toThrowErrorMatchingSnapshot(); expect(mockCreate).toHaveBeenCalledWith(expect.objectContaining({ ...indexBase, assignedContentTypes })); - expect(importModule.enrichIndex).toHaveBeenCalledWith(mockHub, newIndex, index, webhooks); + expect(importModule.enrichIndex).toHaveBeenCalledWith(mockHub, newIndex, index, webhooks, log); + expect(log.getData('CREATE')).toEqual([]); + }); + + it('should wait until the index is created if the initial request returns a 504', async () => { + setTestCheck(true); + const mockHub = new Hub(); + const log = new FileLog(); + const newIndex = new SearchIndex({ id: 'created-id', name: 'index-name' }); + + let created = newIndex; + const mockCreate = jest.fn().mockImplementation(async () => { + created = newIndex; + throw error504; + }); + mockHub.related.searchIndexes.create = mockCreate; + + const mockList = jest.fn().mockImplementation(async () => new MockPage(SearchIndex, [created])); + mockHub.related.searchIndexes.list = mockList; + + jest.spyOn(importModule, 'enrichIndex').mockResolvedValue(); + const indexBase = { name: 'index-name', label: 'test-label' }; + const index = { ...indexBase, assignedContentTypes: [assignedContentType] }; + const webhooks = new Map(); + const result = await doCreate(mockHub, index as EnrichedSearchIndex, webhooks, log); + + expect(log.getData('CREATE')).toMatchInlineSnapshot(` + Array [ + "created-id", + ] + `); + expect(mockCreate).toHaveBeenCalledWith(expect.objectContaining({ ...indexBase, assignedContentTypes })); + expect(importModule.enrichIndex).toHaveBeenCalledWith(mockHub, newIndex, index, webhooks, log); + expect(result).toEqual(newIndex); + }); + + it('should error if the index never appears after a 504', async () => { + setTestCheck(true); + const mockHub = new Hub(); + const log = new FileLog(); + + const mockCreate = jest.fn().mockRejectedValue(error504); + mockHub.related.searchIndexes.create = mockCreate; + + const mockList = jest.fn().mockImplementation(async () => new MockPage(SearchIndex, [])); + mockHub.related.searchIndexes.list = mockList; + + jest.spyOn(importModule, 'enrichIndex').mockResolvedValue(); + const indexBase = { name: 'index-name', label: 'test-label' }; + const index = { ...indexBase, assignedContentTypes: [assignedContentType] }; + const webhooks = new Map(); + + await expect( + doCreate(mockHub, index as EnrichedSearchIndex, webhooks, log) + ).rejects.toThrowErrorMatchingSnapshot(); + + expect(mockCreate).toHaveBeenCalledWith(expect.objectContaining({ ...indexBase, assignedContentTypes })); + expect(importModule.enrichIndex).not.toHaveBeenCalled(); expect(log.getData('CREATE')).toEqual([]); }); }); @@ -250,6 +319,10 @@ describe('search-index import command', (): void => { type.related.unassign = jest.fn().mockReturnValue(Promise.resolve()); } + afterEach(() => { + setTestCheck(false); + }); + it('should fetch settings, content types for comparison with the index to be enriched', async () => { const mockHub = new Hub(); @@ -271,7 +344,7 @@ describe('search-index import command', (): void => { mockHub.related.searchIndexes.get = jest.fn().mockResolvedValue(index); - await enrichIndex(mockHub, index, enrichedIndex, undefined); + await enrichIndex(mockHub, index, enrichedIndex, undefined, new FileLog()); expect(enrichedIndex.settings.replicas).toEqual([]); expect(index.related.settings.get).toHaveBeenCalled(); @@ -326,7 +399,7 @@ describe('search-index import command', (): void => { mockHub.related.searchIndexes.get = jest.fn().mockResolvedValue(index); - await enrichIndex(mockHub, index, enrichedIndex, undefined); + await enrichIndex(mockHub, index, enrichedIndex, undefined, new FileLog()); expect(enrichedIndex.settings.replicas).toEqual(expect.arrayContaining(['replica-1', 'replica-2', 'replica-3'])); expect(enrichedIndex.settings.replicas.length).toEqual(3); @@ -345,6 +418,75 @@ describe('search-index import command', (): void => { expect(mockHub.related.searchIndexes.get).toHaveBeenCalledWith('id-1'); }); + it('should wait until the replica exists if creating it returns a 504 timeout', async () => { + setTestCheck(true); + const mockHub = new Hub(); + + const index = new SearchIndex({ + id: 'id-1', + name: 'index-1', + label: 'index-1' + }); + + const enrichedIndex = new EnrichedSearchIndex({ + settings: { + replicas: ['replica-1', 'replica-2'] + }, + assignedContentTypes: [], + replicas: [ + new EnrichedReplica({ + name: 'replica-1', + settings: new SearchIndexSettings({ setting: '1' }) + }), + new EnrichedReplica({ + name: 'replica-2', + settings: new SearchIndexSettings({ setting: '2' }) + }) + ] + }); + + const indexNames = ['replica-1', 'replica-2', 'replica-3']; + const replicas = indexNames.map(name => { + const index = new SearchIndex({ name }); + index.related.update = jest.fn().mockResolvedValue(index); + index.related.settings.update = jest + .fn() + .mockImplementation(settings => Promise.resolve(new SearchIndexSettings(settings))); + return index; + }); + + let settings = new SearchIndexSettings({ replicas: ['replica-3'] }); + + index.related.settings.get = jest.fn().mockImplementation(async () => settings); + index.related.settings.update = jest.fn().mockImplementation(async newSettings => { + settings = newSettings; + throw error504; + }); + index.related.replicas.list = jest.fn().mockResolvedValue(new MockPage(SearchIndex, replicas)); + index.related.assignedContentTypes.list = jest.fn().mockResolvedValue(new MockPage(AssignedContentType, [])); + index.related.assignedContentTypes.create = jest.fn(); + + mockHub.related.searchIndexes.get = jest.fn().mockResolvedValue(index); + + await enrichIndex(mockHub, index, enrichedIndex, undefined, new FileLog()); + + expect(enrichedIndex.settings.replicas).toEqual(expect.arrayContaining(['replica-1', 'replica-2', 'replica-3'])); + expect(enrichedIndex.settings.replicas.length).toEqual(3); + expect(index.related.settings.get).toHaveBeenCalledTimes(2); + expect(index.related.settings.update).toHaveBeenCalledWith(enrichedIndex.settings, false); + expect(index.related.replicas.list).toHaveBeenCalled(); + + for (let i = 0; i < 2; i++) { + expect((replicas[i].related.update as jest.Mock).mock.calls[0][0].name).toEqual(replicas[i].name); + expect(replicas[i].related.settings.update).toHaveBeenCalledWith(enrichedIndex.replicas[i].settings, false); + } + + expect(index.related.assignedContentTypes.list).toHaveBeenCalled(); + expect(index.related.assignedContentTypes.create).not.toHaveBeenCalled(); + + expect(mockHub.related.searchIndexes.get).toHaveBeenCalledWith('id-1'); + }); + it('should assign any content types that are not yet assigned on the destination index, removing any that are no longer present', async () => { const mockHub = new Hub(); @@ -384,7 +526,7 @@ describe('search-index import command', (): void => { mockHub.related.searchIndexes.get = jest.fn().mockResolvedValue(index); - await enrichIndex(mockHub, index, enrichedIndex, undefined); + await enrichIndex(mockHub, index, enrichedIndex, undefined, new FileLog()); expect(created).toEqual([enrichedIndex.assignedContentTypes[0]]); @@ -437,7 +579,7 @@ describe('search-index import command', (): void => { mockHub.related.searchIndexes.get = jest.fn().mockResolvedValue(index); - await enrichIndex(mockHub, index, enrichedIndex, enrichedWebhooks); + await enrichIndex(mockHub, index, enrichedIndex, enrichedWebhooks, new FileLog()); expect(type.related.unassign).not.toHaveBeenCalled(); expect(index.related.assignedContentTypes.create).not.toHaveBeenCalled(); @@ -515,7 +657,7 @@ describe('search-index import command', (): void => { `); expect(hub.related.searchIndexes.get).toHaveBeenCalledWith('stored-id'); expect(exportModule.enrichIndex).toHaveBeenCalledWith(expect.any(Map), replicas, storedIndex); - expect(importModule.enrichIndex).toHaveBeenCalledWith(hub, updatedIndex, mutatedIndex, webhooks); + expect(importModule.enrichIndex).toHaveBeenCalledWith(hub, updatedIndex, mutatedIndex, webhooks, log); expect(result).toEqual({ index: updatedIndex, updateStatus: UpdateStatus.UPDATED }); expect(mockUpdate.mock.calls[0][0].toJSON()).toEqual(expectedIndex.toJSON()); }); diff --git a/src/commands/search-index/import.ts b/src/commands/search-index/import.ts index f91a636c..136f1896 100644 --- a/src/commands/search-index/import.ts +++ b/src/commands/search-index/import.ts @@ -1,8 +1,10 @@ import chalk from 'chalk'; import { Hub, Page, Pageable, SearchIndex, Settings, Sortable, Webhook } from 'dc-management-sdk-js'; +import { isEqual } from 'lodash'; import { join } from 'path'; import { table } from 'table'; import { Arguments, Argv } from 'yargs'; +import { waitOnTimeout } from '../../common/content-item/retry-helpers'; import paginator from '../../common/dc-management-sdk-js/paginator'; import { FileLog } from '../../common/file-log'; import { createLog, getDefaultLogPath } from '../../common/log-helpers'; @@ -165,7 +167,8 @@ export const enrichIndex = async ( hub: Hub, index: SearchIndex, enrichedIndex: EnrichedSearchIndex, - webhooks: Map | undefined + webhooks: Map | undefined, + log: FileLog ): Promise => { // Union the replicas on the server and the replicas being imported. // This avoids replicas being detached from their parents, and thus becoming unusable. @@ -178,8 +181,17 @@ export const enrichIndex = async ( } enrichedIndex.settings.replicas = Array.from(replicas); - // Update the search index settings. - await index.related.settings.update(enrichedIndex.settings, false); + // Update the search index settings. This may take a while if it ends up creating replicas, so wait if it times out. + await waitOnTimeout( + log, + async () => await index.related.settings.update(enrichedIndex.settings, false), + async () => { + // Request the settings and check if they match. + const settings = await index.related.settings.get(); + + return isEqual(settings, enrichedIndex.settings); + } + ); // Updating the settings might have changed the available hal links, so refetch it. index = await hub.related.searchIndexes.get(index.id as string); @@ -249,9 +261,28 @@ export const doCreate = async ( const toCreate = new SearchIndex({ ...getIndexProperties(index), assignedContentTypes }); - const createdIndex = await hub.related.searchIndexes.create(toCreate); + let creatingIndex: SearchIndex | undefined; + + // Create the search index. This may take a while, so wait if it times out. + await waitOnTimeout( + log, + async () => { + creatingIndex = await hub.related.searchIndexes.create(toCreate); + }, + async () => { + // Request the indexes and see if any of them match our creation request. + + const indexes = await paginator(searchIndexList(hub)); + + creatingIndex = indexes.find(newIndex => index.name === newIndex.name); + + return creatingIndex != null; + } + ); + + const createdIndex = creatingIndex as SearchIndex; // Should be non-null coming out of waitOnTimeout - await enrichIndex(hub, createdIndex, index, webhooks); + await enrichIndex(hub, createdIndex, index, webhooks, log); log.addAction('CREATE', `${createdIndex.id}`); @@ -283,7 +314,7 @@ export const doUpdate = async ( const updatedIndex = await retrievedIndex.related.update(retrievedIndex); - await enrichIndex(hub, updatedIndex, index, webhooks); + await enrichIndex(hub, updatedIndex, index, webhooks, log); log.addAction('UPDATE', `${retrievedIndex.id}`); diff --git a/src/common/content-item/__mocks__/retry-helpers.ts b/src/common/content-item/__mocks__/retry-helpers.ts new file mode 100644 index 00000000..f011cf30 --- /dev/null +++ b/src/common/content-item/__mocks__/retry-helpers.ts @@ -0,0 +1,27 @@ +import { FileLog } from '../../file-log'; + +let testCheck = false; + +export const setTestCheck = (value: boolean): void => { + testCheck = value; +}; + +export const waitOnTimeout = async ( + log: FileLog, + request: () => Promise, + finishedCheck: () => Promise +): Promise => { + if (testCheck) { + try { + await request(); + } catch {} + } else { + await request(); + } + + if (testCheck) { + if (!(await finishedCheck())) { + throw new Error('waitOnTimeout'); + } + } +}; diff --git a/src/common/content-item/retry-helpers.spec.ts b/src/common/content-item/retry-helpers.spec.ts new file mode 100644 index 00000000..de30458a --- /dev/null +++ b/src/common/content-item/retry-helpers.spec.ts @@ -0,0 +1,159 @@ +import { HttpError } from 'dc-management-sdk-js'; +import { FileLog } from '../file-log'; +import { waitOnTimeout } from './retry-helpers'; +import * as retryHelpers from './retry-helpers'; + +describe('retry-helpers', () => { + // eslint-disable-next-line @typescript-eslint/no-explicit-any + const error504 = new HttpError('Error', undefined, { status: 504 } as any); + // eslint-disable-next-line @typescript-eslint/no-explicit-any + const error502 = new HttpError('Error', undefined, { status: 502 } as any); + + beforeEach(() => { + jest.resetAllMocks(); + jest.spyOn(retryHelpers, 'delay').mockResolvedValue(); + }); + + describe('waitOnTimeout', () => { + it('should not call check method when the initial request succeeds', async () => { + const log = new FileLog(); + const request = jest.fn(); + request.mockResolvedValue(null); + const finishedCheck = jest.fn(); + finishedCheck.mockResolvedValue(null); + + await waitOnTimeout(log, request, finishedCheck); + + expect(request).toHaveBeenCalled(); + expect(finishedCheck).not.toHaveBeenCalled(); + expect(log.accessGroup.length).toBe(0); + expect(retryHelpers.delay).not.toHaveBeenCalled(); + }); + + it('should call check method when the initial request fails with a 504, repeatedly until it returns true', async () => { + const log = new FileLog(); + const request = jest.fn(); + request.mockRejectedValue(error504); + const finishedCheck = jest.fn(); + finishedCheck.mockResolvedValueOnce(false); + finishedCheck.mockResolvedValueOnce(false); + finishedCheck.mockResolvedValueOnce(true); + + await waitOnTimeout(log, request, finishedCheck); + + expect(request).toHaveBeenCalled(); + expect(finishedCheck).toHaveBeenCalledTimes(3); + expect(log.accessGroup.length).toBe(3); + expect(retryHelpers.delay).toHaveBeenCalledTimes(3); + }); + + it('should call check method when the initial request fails with a 504, error when the check fails', async () => { + const log = new FileLog(); + const request = jest.fn(); + request.mockRejectedValue(error504); + const finishedCheck = jest.fn(); + finishedCheck.mockResolvedValue(false); + + await expect(waitOnTimeout(log, request, finishedCheck, true, 10)).rejects.toThrowError(error504); + + expect(request).toHaveBeenCalled(); + expect(finishedCheck).toHaveBeenCalledTimes(10); + expect(log.accessGroup.length).toBe(11); + expect(retryHelpers.delay).toHaveBeenCalledTimes(10); + }); + + it('should error and not call check method when the initial request fails with an error that has no response', async () => { + const log = new FileLog(); + const request = jest.fn(); + request.mockRejectedValue(error504); + const finishedCheck = jest.fn(); + finishedCheck.mockResolvedValue(false); + + // Still throws even if throwErrors is false. + await expect(waitOnTimeout(log, request, finishedCheck, false, 10)).rejects.toThrowError(error504); + + expect(request).toHaveBeenCalled(); + expect(finishedCheck).toHaveBeenCalledTimes(10); + expect(log.accessGroup.length).toBe(11); + expect(retryHelpers.delay).toHaveBeenCalledTimes(10); + }); + + it('should error and not call check method when the initial request fails with a non-504 error', async () => { + const log = new FileLog(); + const request = jest.fn(); + request.mockRejectedValue(error502); + const finishedCheck = jest.fn(); + + await expect(waitOnTimeout(log, request, finishedCheck)).rejects.toThrowError(error502); + + expect(request).toHaveBeenCalled(); + expect(finishedCheck).not.toHaveBeenCalled(); + expect(log.accessGroup.length).toBe(0); + expect(retryHelpers.delay).not.toHaveBeenCalled(); + }); + + it('should call check method when the initial request fails with a non-504 when throwErrors argument is false', async () => { + const log = new FileLog(); + const request = jest.fn(); + request.mockRejectedValue(error502); + const finishedCheck = jest.fn(); + finishedCheck.mockResolvedValueOnce(false); + finishedCheck.mockResolvedValueOnce(false); + finishedCheck.mockResolvedValueOnce(true); + + await waitOnTimeout(log, request, finishedCheck, false); + + expect(request).toHaveBeenCalled(); + expect(finishedCheck).toHaveBeenCalledTimes(3); + expect(log.accessGroup.length).toBe(3); + expect(retryHelpers.delay).toHaveBeenCalledTimes(3); + }); + + it('should ignore errors when calling the check method', async () => { + const log = new FileLog(); + const request = jest.fn(); + request.mockRejectedValue(error504); + const finishedCheck = jest.fn(); + finishedCheck.mockRejectedValueOnce(error502); + finishedCheck.mockRejectedValueOnce(new Error('Generic Error')); + finishedCheck.mockResolvedValueOnce(true); + + await waitOnTimeout(log, request, finishedCheck, false); + + expect(request).toHaveBeenCalled(); + expect(finishedCheck).toHaveBeenCalledTimes(3); + expect(log.accessGroup.length).toBe(5); + expect(retryHelpers.delay).toHaveBeenCalledTimes(3); + }); + + it('should rethrow the last error when calling the check method and it errors', async () => { + const log = new FileLog(); + const request = jest.fn(); + request.mockRejectedValue(error504); + const finishedCheck = jest.fn(); + finishedCheck.mockRejectedValueOnce(error502); + + await expect(waitOnTimeout(log, request, finishedCheck, false, 1)).rejects.toThrowError(error502); + + expect(request).toHaveBeenCalled(); + expect(finishedCheck).toHaveBeenCalledTimes(1); + expect(log.accessGroup.length).toBe(1); + expect(retryHelpers.delay).toHaveBeenCalledTimes(1); + }); + + it('should rethrow the initial error when calling the check method and it returns false every time', async () => { + const log = new FileLog(); + const request = jest.fn(); + request.mockRejectedValue(error504); + const finishedCheck = jest.fn(); + finishedCheck.mockResolvedValue(false); + + await expect(waitOnTimeout(log, request, finishedCheck, false, 1)).rejects.toThrowError(error504); + + expect(request).toHaveBeenCalled(); + expect(finishedCheck).toHaveBeenCalledTimes(1); + expect(log.accessGroup.length).toBe(2); + expect(retryHelpers.delay).toHaveBeenCalledTimes(1); + }); + }); +}); diff --git a/src/common/content-item/retry-helpers.ts b/src/common/content-item/retry-helpers.ts new file mode 100644 index 00000000..8b44f312 --- /dev/null +++ b/src/common/content-item/retry-helpers.ts @@ -0,0 +1,54 @@ +import { HttpError } from 'dc-management-sdk-js'; +import { FileLog } from '../file-log'; + +export const delay = (duration: number): Promise => { + return new Promise((resolve): void => { + setTimeout(resolve, duration); + }); +}; + +export const waitOnTimeout = async ( + log: FileLog, + request: () => Promise, + finishedCheck: () => Promise, + throwErrors = true, + retries = 30 +): Promise => { + try { + await request(); + } catch (error) { + // If the HTTP error indicates a timeout, loop on the finished check until true, or the retry count is reached. + + const httpError = error as HttpError; + + // If the error doesn't have a response and the status is not 504, rethrow the exception. + if (httpError.response == null || (throwErrors && httpError.response.status != 504)) { + throw error; + } + + // The error was a timeout. Periodically run the finished check to determine if the operation has completed. + for (let i = 0; i < retries; i++) { + try { + log.appendLine(`Retrying... ${i + 1}/${retries}`); + + await delay(1000); + + if (await finishedCheck()) { + break; + } + } catch (error) { + // Retry failed, somehow. + if (retries === i + 1) { + throw error; + } else { + log.appendLine(`Retry failed. Continuing...`); + } + } + + if (retries === i + 1) { + log.appendLine(`Out of retries. Throwing the original error.`); + throw httpError; + } + } + } +};