[pluginSystem] optimize plugins stop execution (#164831)

## Summary

Related to https://github.com/elastic/kibana/issues/163519

Optimize the way we're shutting down plugins, by calling `stop` for each
plugin as soon as all dependant plugins are stopped, instead of just
doing it one-by-one.
This commit is contained in:
Pierre Gayvallet 2023-08-27 12:57:58 +02:00 committed by GitHub
parent ac7113cb45
commit 9f83684f5f
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
2 changed files with 154 additions and 11 deletions

View file

@ -202,6 +202,7 @@ test('correctly orders plugins and returns exposed values for "setup" and "start
setup: Record<PluginName, unknown>;
start: Record<PluginName, unknown>;
}
const plugins = new Map([
[
createPlugin('order-4', { required: ['order-2'] }),
@ -754,6 +755,70 @@ describe('stop', () => {
jest.useRealTimers();
});
const nextTick = () => new Promise((resolve) => setImmediate(resolve));
it('stops all plugins', async () => {
const [plugin1, plugin2, plugin3] = [
createPlugin('plugin-1'),
createPlugin('plugin-2'),
createPlugin('plugin-3'),
].map((plugin, index) => {
jest.spyOn(plugin, 'setup').mockResolvedValue(`setup-as-${index}`);
jest.spyOn(plugin, 'start').mockResolvedValue(`started-as-${index}`);
pluginsSystem.addPlugin(plugin);
return plugin;
});
const stopSpy1 = jest.spyOn(plugin1, 'stop').mockImplementationOnce(() => Promise.resolve());
const stopSpy2 = jest.spyOn(plugin2, 'stop').mockImplementationOnce(() => Promise.resolve());
const stopSpy3 = jest.spyOn(plugin3, 'stop').mockImplementationOnce(() => Promise.resolve());
mockCreatePluginSetupContext.mockImplementation(() => ({}));
await pluginsSystem.setupPlugins(setupDeps);
const stopPromise = pluginsSystem.stopPlugins();
await nextTick();
jest.runAllTimers();
await stopPromise;
expect(stopSpy1).toHaveBeenCalledTimes(1);
expect(stopSpy2).toHaveBeenCalledTimes(1);
expect(stopSpy3).toHaveBeenCalledTimes(1);
});
it('stops plugins in the correct order', async () => {
// stop order: 3 => 1 => 2
const [plugin1, plugin2, plugin3] = [
createPlugin('plugin-1', { required: ['plugin-2'] }),
createPlugin('plugin-2'),
createPlugin('plugin-3', { required: ['plugin-1', 'plugin-2'] }),
].map((plugin, index) => {
jest.spyOn(plugin, 'setup').mockResolvedValue(`setup-as-${index}`);
jest.spyOn(plugin, 'start').mockResolvedValue(`started-as-${index}`);
pluginsSystem.addPlugin(plugin);
return plugin;
});
const stopSpy1 = jest.spyOn(plugin1, 'stop').mockImplementationOnce(() => Promise.resolve());
const stopSpy2 = jest.spyOn(plugin2, 'stop').mockImplementationOnce(() => Promise.resolve());
const stopSpy3 = jest.spyOn(plugin3, 'stop').mockImplementationOnce(() => Promise.resolve());
mockCreatePluginSetupContext.mockImplementation(() => ({}));
await pluginsSystem.setupPlugins(setupDeps);
const stopPromise = pluginsSystem.stopPlugins();
await nextTick();
jest.runAllTimers();
await stopPromise;
expect(stopSpy3.mock.invocationCallOrder[0]).toBeLessThan(stopSpy1.mock.invocationCallOrder[0]);
expect(stopSpy1.mock.invocationCallOrder[0]).toBeLessThan(stopSpy2.mock.invocationCallOrder[0]);
});
it('waits for 30 sec to finish "stop" and move on to the next plugin.', async () => {
const [plugin1, plugin2] = [createPlugin('timeout-stop-1'), createPlugin('timeout-stop-2')].map(
(plugin, index) => {
@ -774,8 +839,11 @@ describe('stop', () => {
await pluginsSystem.setupPlugins(setupDeps);
const stopPromise = pluginsSystem.stopPlugins();
await nextTick();
jest.runAllTimers();
await stopPromise;
expect(stopSpy1).toHaveBeenCalledTimes(1);
expect(stopSpy2).toHaveBeenCalledTimes(1);
@ -785,4 +853,42 @@ describe('stop', () => {
])
);
});
it('logs a message if a plugin fails top stop', async () => {
// stop order: 3 => 1 => 2
const [plugin1, plugin2, plugin3] = [
createPlugin('plugin-1', { required: ['plugin-2'] }),
createPlugin('plugin-2'),
createPlugin('plugin-3', { required: ['plugin-1', 'plugin-2'] }),
].map((plugin, index) => {
jest.spyOn(plugin, 'setup').mockResolvedValue(`setup-as-${index}`);
jest.spyOn(plugin, 'start').mockResolvedValue(`started-as-${index}`);
pluginsSystem.addPlugin(plugin);
return plugin;
});
const stopSpy1 = jest
.spyOn(plugin1, 'stop')
.mockImplementationOnce(() => Promise.reject('woups'));
const stopSpy2 = jest.spyOn(plugin2, 'stop').mockImplementationOnce(() => Promise.resolve());
const stopSpy3 = jest.spyOn(plugin3, 'stop').mockImplementationOnce(() => Promise.resolve());
mockCreatePluginSetupContext.mockImplementation(() => ({}));
await pluginsSystem.setupPlugins(setupDeps);
const stopPromise = pluginsSystem.stopPlugins();
await nextTick();
jest.runAllTimers();
await stopPromise;
expect(stopSpy1).toHaveBeenCalledTimes(1);
expect(stopSpy2).toHaveBeenCalledTimes(1);
expect(stopSpy3).toHaveBeenCalledTimes(1);
expect(loggingSystemMock.collect(logger).warn.flat()).toEqual(
expect.arrayContaining([`"plugin-1" thrown during stop: woups`])
);
});
});

View file

@ -224,21 +224,38 @@ export class PluginsSystem<T extends PluginType> {
this.log.info(`Stopping all plugins.`);
// Stop plugins in the reverse order of when they were set up.
while (this.satupPlugins.length > 0) {
const pluginName = this.satupPlugins.pop()!;
const reverseDependencyMap = buildReverseDependencyMap(this.plugins);
const pluginStopPromiseMap = new Map<PluginName, Promise<void>>();
for (let i = this.satupPlugins.length - 1; i > -1; i--) {
const pluginName = this.satupPlugins[i];
const plugin = this.plugins.get(pluginName)!;
const pluginDependant = reverseDependencyMap.get(pluginName)!;
const dependantPromises = pluginDependant.map(
(dependantName) => pluginStopPromiseMap.get(dependantName)!
);
this.log.debug(`Stopping plugin "${pluginName}"...`);
// Stop plugin as soon as all the dependant plugins are stopped.
const pluginStopPromise = Promise.all(dependantPromises).then(async () => {
this.log.debug(`Stopping plugin "${pluginName}"...`);
const resultMaybe = await withTimeout({
promise: this.plugins.get(pluginName)!.stop(),
timeoutMs: 30 * Sec,
try {
const resultMaybe = await withTimeout({
promise: plugin.stop(),
timeoutMs: 30 * Sec,
});
if (resultMaybe?.timedout) {
this.log.warn(`"${pluginName}" plugin didn't stop in 30sec., move on to the next.`);
}
} catch (e) {
this.log.warn(`"${pluginName}" thrown during stop: ${e}`);
}
});
if (resultMaybe?.timedout) {
this.log.warn(`"${pluginName}" plugin didn't stop in 30sec., move on to the next.`);
}
pluginStopPromiseMap.set(pluginName, pluginStopPromise);
}
await Promise.allSettled(pluginStopPromiseMap.values());
this.log.info(`All plugins stopped.`);
}
/**
@ -334,3 +351,23 @@ export class PluginsSystem<T extends PluginType> {
return sortedPluginNames;
}
}
const buildReverseDependencyMap = (
pluginMap: Map<PluginName, PluginWrapper>
): Map<PluginName, PluginName[]> => {
const reverseMap = new Map<PluginName, PluginName[]>();
for (const pluginName of pluginMap.keys()) {
reverseMap.set(pluginName, []);
}
for (const [pluginName, pluginWrapper] of pluginMap.entries()) {
const allDependencies = [...pluginWrapper.requiredPlugins, ...pluginWrapper.optionalPlugins];
for (const dependency of allDependencies) {
// necessary to evict non-present optional dependency
if (pluginMap.has(dependency)) {
reverseMap.get(dependency)!.push(pluginName);
}
}
reverseMap.set(pluginName, []);
}
return reverseMap;
};