Optimize saved objects getScopedClient and HTTP API #68221

rudolf · 2020-06-04T08:37:14Z

Summary

When the spaces plugin is enabled to secure the saved objects client and the HTTP API we create several saved object repositories for every request. Because we're re-calculating the active mappings for every saved objects repository that's created this creates a performance bottleneck.

This PR optimizes the performance by caching the active mappings making it faster to create repositories and also by re-using the same repository in the spaces client's getScopedClient method.

It further uses shareReplay for the the config$ observable we provide to plugins to prevent running config path validation every time a plugin reads from it's config observable.

Note: There's also a lot of time spent in legacy code that augments the hapi request object with uisettings which is unnecessary, but I'm leaving that as is for now

kibana/src/legacy/ui/ui_settings/ui_settings_service_for_request.ts

Line 40 in 5676ac0

const savedObjectsClient = request.getSavedObjectsClient();

Thanks for the profiling work @nchaulet and the fleet team.

Checklist

Delete any items that are not applicable to this PR.

Any text added follows EUI's writing guidelines, uses sentence case text and includes i18n support
Documentation was added for features that require explanation or tutorials
Unit or functional tests were updated or added to match the most common scenarios
This was checked for keyboard-only and screenreader accessibility
This renders correctly on smaller devices using a responsive layout. (You can test this in your browser
This was checked for cross-browser compatibility, including a check against IE11

For maintainers

This was checked for breaking API changes and was labeled appropriately

jfsiii · 2020-06-04T11:03:45Z

I took a look at this locally and it looks outstanding. I'm happy to provide more details about recreating the test or viewing the cpu profiles but here are some notes

Test

1000 connections to /api/features [1] for 60secs

TL;DR: Huge improvements in key areas

RPS: 34 -> 178
Event loop delay: 3000ms -> 200ms

Master

Completed 2K requests. 4K errors
Median response time ~8.5s
Event loop delays of 3000ms (3 seconds)

PR

Completes 11K requests. 4K errors
Median response time ~1.1s
Event loop delays of 150ms-200ms (0.15-0.2 seconds)

[1] Chose /api/features since it's outside the Ingest Manager plugin and, IIUC, doesn't do any Saved Object or much other route. We've been using this as a realistic example of Kibana perf/overhead

…ings)

jfsiii · 2020-06-04T14:48:10Z

I initially showed tests against /api/features to demonstrate that the changes should benefit all Kibana, but here's a Fleet specific example.

This is hitting /api/enroll with 10, 50, 100, 150, and finally 250 connections. Initially in the PR branch, then on master.

Sorry for the "after"/"before" arrangement but the event loop improvements are still present

enroll command

autocannon -c 100 -d 60 --method POST --header 'kbn-xsrf: xxx' --header 'Authorization: ApiKey cDl1LWZISUJ2d3RqeklLdGhUVnY6RHdHRmhMbFdSVEt2VDFUamtTZ0NKQQ==' --header 'Content-Type: application/json' --body '{
    "type": "PERMANENT",
    "metadata": {
        "local": {
            "host": "localhost",
            "ip": "127.0.0.1",
            "system": "Darwin 18.7.0",
            "memory": 34359738368
        },
        "user_provided": {
            "dev_agent_version": "0.0.1",
            "region": "us-east"
        }
    }
}' http://localhost:5601/api/ingest_manager/fleet/agents/enroll

rudolf · 2020-06-04T14:52:27Z

I've pushed some more changes and I think we've now removed all the low hanging fruit.

Most of the time is now spent in validating the request which takes 0.4ms or ~10% of the time

kibana/src/core/server/http/router/validator/validator.ts

Line 284 in f6f610d

return schema.maybe(schema.nullable(schema.any({})));

This will probably be a lot more with more complex validation, but we will have to profile the fleet API again to see what specifically is taking up time in that route.

nchaulet · 2020-06-04T14:52:49Z

I did some tests also and CPU profile while enrolling 250 agents, and the improvments seems to be great, next bottleneck are on our side :)

cpu-profile-after.cpuprofile.zip

These one still seems to be improved, I think it's related to used filter in a saved object query

rudolf · 2020-06-04T14:56:40Z

These one still seems to be improved, I think it's related to used filter in a saved object query

Yeah it looks like we're hitting performance bottleneck in the KQL parser, fun times

rudolf · 2020-06-04T16:34:06Z

src/core/server/plugins/plugin_context.ts

-      create() {
-        return coreContext.configService.atPath(pluginManifest.configPath);
+      create<T>() {
+        return coreContext.configService.atPath<T>(pluginManifest.configPath).pipe(shareReplay(1));


The spaces plugin takes a config value for every getScopedClient call (every incoming request). This does config validation for this config path each time.

kibana/x-pack/plugins/spaces/server/spaces_service/spaces_service.ts

Lines 75 to 82 in c5e446a

const getScopedClient = async (request: KibanaRequest) => {

const [coreStart] = await getStartServices();

const internalRepository = await internalRepositoryPromise;

return config$

.pipe(

take(1),

map((config) => {

We could optimize the plugin to not take a new config value every time but only if a new value was emitted, but this felt like a better fix that will probably benefit other places.

rudolf · 2020-06-04T16:36:01Z

src/core/server/saved_objects/service/lib/repository.ts

@@ -136,7 +136,7 @@ export class SavedObjectsRepository {
    injectedConstructor: any = SavedObjectsRepository
  ): ISavedObjectsRepository {
    const mappings = migrator.getActiveMappings();
-    const allTypes = Object.keys(getRootPropertiesObjects(mappings));
+    const allTypes = typeRegistry.getAllTypes().map((t) => t.name);


apparently Object.entries() which gets called from inside getRootPropertiesObjects is very slow.

Pierre already refactored many places where we use this round about getRootPropertiesObjects way to get all the types, but there's still a few remaining.

Some getRootPropertiesObjects were kept because of the config 'virtual' type that wasn't properly registered to the registry. But this has been resolved since, so we're safe to remove all the remaining usages.

Very surprised Object.keys is a bottleneck, even if it makes sense that typeRegistry.getAllTypes() is faster as the registry is based on a Map.

Probably it's not Object.keys but getRootPropertiesObjects mutating an object?

kibana/src/core/server/saved_objects/mappings/lib/get_root_properties_objects.ts

Line 52 in 3d39cd5

acc[key] = value;

v8 cannot optimizie this case https://richardartoul.github.io/jekyll/update/2015/04/26/hidden-classes.html

Right, I misread and thought it was just a call to getRootProperties

This was the line that showed up in the profiler and took almost 5ms:

kibana/src/core/server/saved_objects/mappings/lib/get_root_properties_objects.ts

Line 46 in ea7c78d

return Object.entries(rootProperties).reduce((acc, [key, value]) => {

rudolf · 2020-06-04T16:39:32Z

x-pack/plugins/spaces/server/spaces_service/spaces_service.ts

    const getScopedClient = async (request: KibanaRequest) => {
      const [coreStart] = await getStartServices();
+      const internalRepository = await internalRepositoryPromise;


createScopedRepository already creates a new repository for every request, so after the other improvements it's probably not that critical that we re-use this repository instead of creating a new one. But since this is on the hot path it felt like it doesn't hurt to keep this minor improvement around.

elasticmachine · 2020-06-04T16:41:46Z

Pinging @elastic/kibana-platform (Team:Platform)

kibanamachine · 2020-06-04T18:09:06Z

💚 Build Succeeded

continuous-integration/kibana-ci/pull-request
Commit: 9ffcf55

History

💔 Build #51760 failed cc98fa6
💚 Build #51678 succeeded ef30e36

To update your PR or re-run it, just comment with:
@elasticmachine merge upstream

pgayvallet

LGTM

pgayvallet · 2020-06-05T06:46:31Z

src/core/server/saved_objects/service/lib/repository.ts

@@ -136,7 +136,7 @@ export class SavedObjectsRepository {
    injectedConstructor: any = SavedObjectsRepository
  ): ISavedObjectsRepository {
    const mappings = migrator.getActiveMappings();
-    const allTypes = Object.keys(getRootPropertiesObjects(mappings));
+    const allTypes = typeRegistry.getAllTypes().map((t) => t.name);


Some getRootPropertiesObjects were kept because of the config 'virtual' type that wasn't properly registered to the registry. But this has been resolved since, so we're safe to remove all the remaining usages.

Very surprised Object.keys is a bottleneck, even if it makes sense that typeRegistry.getAllTypes() is faster as the registry is based on a Map.

mshustov · 2020-06-05T07:11:38Z

Note: There's also a lot of time spent in legacy code that augments the hapi request object with uisettings which is unnecessary, but I'm leaving that as is for now

We are removing this code in v7.10 anyway

legrego

LGTM!

ruflin · 2020-06-08T08:36:26Z

@rudolf Really excited to see this performance improvement. I wonder if there is a way that we keep "track" of these improvements to make sure not a follow up change in KB accidentally invalidates this optimisation again.

* master: (57 commits) Add app arch team as owner of datemath package (elastic#66880) [Observability] Landing page for Observability (elastic#67467) [SIEM] Fix timeline buildGlobalQuery (elastic#68320) Optimize saved objects getScopedClient and HTTP API (elastic#68221) [Maps] Fix mb-style interpolate style rule (elastic#68413) update script to always download node (elastic#68421) [SECURITY SOLEIL] Fix selection of event type when no siem index signal created (elastic#68291) [DOCS] Adds note about configuring File Data Visualizer (elastic#68407) [DOCS] Adds link from remote clusters to index patterns (elastic#68406) [QA] slack notify on failure (elastic#68126) upgrade eslint-plugin-react-hooks from 2.3.0 to 4.0.4 (elastic#68295) moving to jira to a gold license (elastic#67178) [DOCS] Revises doc on adding data (elastic#68038) [APM] Add ThemeProvider to support dark mode (elastic#68242) Make welcome screen disabling first action in loginIfPrompted (elastic#68238) [QA] Code coverage: unskip tests, collect tests results, exclude bundles from report (elastic#64477) [ML] Functional tests - disable flaky regression and classification creation test [Alerting] change eventLog ILM requests to absolute URLs (elastic#68331) Report page load asset size (elastic#66224) [SIEM][CASE] Change SIEM to Security (elastic#68365) ...

* Create a single repository to be shared by all calls to getScopedClient * Cache migrator.getActiveMappings to improve createRepository * Use typeregistry.getAllTypes instead of getRootPropertiesObjects(mappings) * Don't validate plugin's config every time it's read * Fix saved_objects_mixin Co-authored-by: Elastic Machine <elasticmachine@users.noreply.github.com>

mshustov · 2020-06-09T08:21:12Z

@ruflin there was a discussion on GAH to automate perf checks #63848
@LeeDr Do we have a dedicated issue for this? I cannot find any in Kibana-QA Team Roadmap.

rudolf added 2 commits June 4, 2020 10:07

Create a single repository to be shared by all calls to getScopedClient

c5e446a

Cache migrator.getActiveMappings to improve createRepository

ef30e36

rudolf added 2 commits June 4, 2020 14:15

Use typeregistry.getAllTypes instead of getRootPropertiesObjects(mapp…

fa04609

…ings)

Don't validate plugin's config every time it's read

cc98fa6

jfsiii mentioned this pull request Jun 4, 2020

[Ingest Manager] How to reduce the overhead of Kibana in the work our routes does #67989

Closed

Fix saved_objects_mixin

9ffcf55

rudolf commented Jun 4, 2020

View reviewed changes

rudolf marked this pull request as ready for review June 4, 2020 16:41

rudolf requested review from a team as code owners June 4, 2020 16:41

rudolf added Team:Core Core services & architecture: plugins, logging, config, saved objects, http, ES client, i18n, etc v7.9.0 v8.0.0 labels Jun 4, 2020

rudolf added this to Pending Review in kibana-core [DEPRECATED] via automation Jun 4, 2020

rudolf added the release_note:skip Skip the PR/issue when compiling release notes label Jun 4, 2020

pgayvallet approved these changes Jun 5, 2020

View reviewed changes

legrego approved these changes Jun 5, 2020

View reviewed changes

rudolf merged commit 2559dbe into elastic:master Jun 5, 2020

kibana-core [DEPRECATED] automation moved this from Pending Review to Done (7.9) Jun 5, 2020

rudolf deleted the optimize-saved-objects-api branch June 5, 2020 23:05

rudolf mentioned this pull request Jun 5, 2020

[7.x] Optimize saved objects getScopedClient and HTTP API (#68221) #68461

Merged

jfsiii mentioned this pull request Jun 8, 2020

[Ingest][EPM] Ingest Manager start lifecycle didn't finish in 30 secs #66125

Closed

jfsiii mentioned this pull request Jun 17, 2020

[Ingest Manager] Protect Kibana of spikes cause by Elastic Agent enrollment or checkin. #67987

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Optimize saved objects getScopedClient and HTTP API #68221

Optimize saved objects getScopedClient and HTTP API #68221

rudolf commented Jun 4, 2020 •

edited

Loading

jfsiii commented Jun 4, 2020 •

edited

Loading

jfsiii commented Jun 4, 2020

rudolf commented Jun 4, 2020

nchaulet commented Jun 4, 2020 •

edited

Loading

rudolf commented Jun 4, 2020

rudolf Jun 4, 2020

rudolf Jun 4, 2020

pgayvallet Jun 5, 2020

mshustov Jun 5, 2020 •

edited

Loading

pgayvallet Jun 5, 2020

rudolf Jun 5, 2020

rudolf Jun 4, 2020

elasticmachine commented Jun 4, 2020

kibanamachine commented Jun 4, 2020

pgayvallet left a comment

pgayvallet Jun 5, 2020

mshustov commented Jun 5, 2020

legrego left a comment

ruflin commented Jun 8, 2020

mshustov commented Jun 9, 2020

	const getScopedClient = async (request: KibanaRequest) => {
	const [coreStart] = await getStartServices();
	const internalRepository = await internalRepositoryPromise;

	return config$
	.pipe(
	take(1),
	map((config) => {

Optimize saved objects getScopedClient and HTTP API #68221

Optimize saved objects getScopedClient and HTTP API #68221

Conversation

rudolf commented Jun 4, 2020 • edited Loading

Summary

Checklist

For maintainers

jfsiii commented Jun 4, 2020 • edited Loading

Test

Master

PR

jfsiii commented Jun 4, 2020

rudolf commented Jun 4, 2020

nchaulet commented Jun 4, 2020 • edited Loading

rudolf commented Jun 4, 2020

rudolf Jun 4, 2020

Choose a reason for hiding this comment

rudolf Jun 4, 2020

Choose a reason for hiding this comment

pgayvallet Jun 5, 2020

Choose a reason for hiding this comment

mshustov Jun 5, 2020 • edited Loading

Choose a reason for hiding this comment

pgayvallet Jun 5, 2020

Choose a reason for hiding this comment

rudolf Jun 5, 2020

Choose a reason for hiding this comment

rudolf Jun 4, 2020

Choose a reason for hiding this comment

elasticmachine commented Jun 4, 2020

kibanamachine commented Jun 4, 2020

💚 Build Succeeded

History

pgayvallet left a comment

Choose a reason for hiding this comment

pgayvallet Jun 5, 2020

Choose a reason for hiding this comment

mshustov commented Jun 5, 2020

legrego left a comment

Choose a reason for hiding this comment

ruflin commented Jun 8, 2020

mshustov commented Jun 9, 2020

rudolf commented Jun 4, 2020 •

edited

Loading

jfsiii commented Jun 4, 2020 •

edited

Loading

nchaulet commented Jun 4, 2020 •

edited

Loading

mshustov Jun 5, 2020 •

edited

Loading