Fix search telemetry to only update SO periodically #93130

lukasolson · 2021-03-01T21:26:09Z

Summary

Resolves #92055.

We have gotten a few reports that collecting telemetry for search requests (success/error/duration) can cause significant load in some high-demand clusters. Specifically, there have been reports that there are a lot of requests to update the saved object when search requests return.

This PR updates the behavior so that we only update the saved object at most once every 5 seconds, which should not only reduce the load, but also result in fewer version conflict errors.

elasticmachine · 2021-03-01T21:26:12Z

Pinging @elastic/kibana-app-services (Team:AppServices)

lizozom · 2021-03-02T14:52:48Z

src/plugins/data/server/search/collectors/usage.ts

+
+        // Since search requests may have completed while the saved object was being updated, we minus
+        // what was just updated in the saved object rather than resetting the values to 0
+        collectedUsage.successCount -= attributes.successCount ?? 0;


You may have a race condition here, if collectedUsage gets updated while the incrementCounter request is ongoing. Then you would delete unsaved telemetry.

Should be reset from counterFields rather than attributes

lizozom · 2021-03-02T14:53:43Z

src/plugins/data/server/search/collectors/usage.ts

@@ -64,6 +81,7 @@ export function usageProvider(core: CoreSetup): SearchUsage {
 export function searchUsageObserver(logger: Logger, usage?: SearchUsage) {
  return {
    next(response: IEsSearchResponse) {
+      if (!isCompleteResponse(response)) return;


lukasolson · 2021-03-05T20:04:45Z

@elasticmachine merge upstream

# Conflicts: # api_docs/core.json # api_docs/core_http.json # api_docs/fleet.json

Dosant

Tested. See telemetry debounced.

Dosant · 2021-03-10T13:21:11Z

src/plugins/data/server/search/collectors/usage.ts

@@ -64,6 +82,7 @@ export function usageProvider(core: CoreSetup): SearchUsage {
 export function searchUsageObserver(logger: Logger, usage?: SearchUsage) {
  return {
    next(response: IEsSearchResponse) {
+      if (!isCompleteResponse(response)) return;
      logger.debug(`trackSearchStatus:next  ${response.rawResponse.took}`);
      usage?.trackSuccess(response.rawResponse.took);


Probably not related to this pr, but I want to point out:

When we restore a search session then this took is the original time that query took.

so assume:

Doing a search the first time - Request completes in ~10ms and took is 10ms

Restoring a search session - Request completes ~3ms and took is still 10ms

I wonder if we actually want to track this took here

Good point, we probably don't want to track at all if isRestore is set to true.

Dosant · 2021-03-10T13:21:29Z

src/plugins/data/server/search/collectors/usage.ts

+        .filter(({ incrementBy }) => incrementBy > 0);
+
+      try {
+        await repository.incrementCounter<CollectedUsage>(


nit: Could it be that repository.incrementCounter took so long that the next request is starting? In this case, the next request will pick up incorrect stats.
I assume this won't happen as 5 seconds is a huge margin and we can leave it as is.

Yeah, I guess that's a possible edge case. I would think Kibana would be pretty much unusable if an incrementCounter request takes more than 5s, so we'll leave it as is for now.

Dosant · 2021-03-10T13:24:52Z

src/plugins/data/server/search/collectors/usage.ts

-      }
-    }
+  const collectedUsage: CollectedUsage = {
+    successCount: 0,


nit: we are dynamically mapping these fields into telemetry objects. I wonder if this dynamic mapping makes it very easy to change field names without realizing that this breaks about telemetry logs structure.

I wonder if this might have some implications if we work in clustering mode 🤔
#68626

kibanamachine · 2021-03-11T02:22:22Z

💚 Build Succeeded

Metrics [docs]

✅ unchanged

History

💔 Build #112653 failed 47d464b
💔 Build #112620 failed dc8ec11
💔 Build #112585 failed f59338a
💚 Build #112442 succeeded 358f500
💚 Build #112141 succeeded b30416b

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

cc @lukasolson

* Fix search telemetry to only update SO periodically * Handle case when searches completed mid flight * Fix error in resetting counters * Update docs * update docs * Don't track restored searches * Update docs * Update docs Co-authored-by: Kibana Machine <[email protected]> Co-authored-by: Anton Dosov <[email protected]>

* Fix search telemetry to only update SO periodically * Handle case when searches completed mid flight * Fix error in resetting counters * Update docs * update docs * Don't track restored searches * Update docs * Update docs Co-authored-by: Kibana Machine <[email protected]> Co-authored-by: Anton Dosov <[email protected]> # Conflicts: # api_docs/cases.json # api_docs/data_search.json # api_docs/lists.json # api_docs/security_solution.json

* Fix search telemetry to only update SO periodically * Handle case when searches completed mid flight * Fix error in resetting counters * Update docs * update docs * Don't track restored searches * Update docs * Update docs Co-authored-by: Kibana Machine <[email protected]> Co-authored-by: Anton Dosov <[email protected]> Co-authored-by: Kibana Machine <[email protected]> Co-authored-by: Anton Dosov <[email protected]>

Fix search telemetry to only update SO periodically

17c5d65

lukasolson added review Feature:Search Querying infrastructure in Kibana Feature:Telemetry v8.0.0 Team:AppServices release_note:skip Skip the PR/issue when compiling release notes v7.12.0 labels Mar 1, 2021

lukasolson requested review from lizozom and Dosant March 1, 2021 21:26

lukasolson self-assigned this Mar 1, 2021

lukasolson requested a review from a team as a code owner March 1, 2021 21:26

lukasolson removed the review label Mar 1, 2021

Handle case when searches completed mid flight

9d559bd

lukasolson added the review label Mar 1, 2021

lizozom reviewed Mar 2, 2021

View reviewed changes

Fix error in resetting counters

6cf229c

lukasolson requested a review from lizozom March 2, 2021 17:36

lukasolson added 3 commits March 3, 2021 15:47

Merge branch 'master' into fix/92055

709f84b

Merge branch 'master' into fix/92055

c61a657

Update docs

38068d7

Merge branch 'master' into fix/92055

4e4cd23

lukasolson added the v7.13.0 label Mar 5, 2021

lukasolson and others added 4 commits March 8, 2021 10:44

Merge branch 'master' into fix/92055

4b06ddd

Merge branch 'master' into fix/92055

4a638b1

Merge branch 'master' into fix/92055

b30416b

Merge branch 'master' of github.com:elastic/kibana into fix/92055

ca6ffb8

# Conflicts: # api_docs/core.json # api_docs/core_http.json # api_docs/fleet.json

update docs

358f500

Dosant approved these changes Mar 10, 2021

View reviewed changes

lukasolson added 2 commits March 10, 2021 11:38

Merge branch 'master' into fix/92055

4d82f94

Don't track restored searches

f59338a

lukasolson force-pushed the fix/92055 branch from 358f500 to f59338a Compare March 10, 2021 18:59

lukasolson added 4 commits March 10, 2021 13:56

Update api docs

dc8ec11

Merge branch 'master' into fix/92055

64972b5

Update docs

47d464b

Update docs

0be6151

lukasolson merged commit 813e16f into elastic:master Mar 11, 2021

lukasolson mentioned this pull request Mar 11, 2021

[7.x] Fix search telemetry to only update SO periodically (#93130) #94454

Merged

lukasolson mentioned this pull request Mar 11, 2021

[7.12] Fix search telemetry to only update SO periodically (#93130) #94455

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Fix search telemetry to only update SO periodically #93130

Fix search telemetry to only update SO periodically #93130

lukasolson commented Mar 1, 2021

elasticmachine commented Mar 1, 2021

lizozom Mar 2, 2021 •

edited

Loading

lukasolson Mar 2, 2021

lizozom Mar 2, 2021

lukasolson commented Mar 5, 2021

Dosant left a comment

Dosant Mar 10, 2021

lukasolson Mar 10, 2021

Dosant Mar 10, 2021 •

edited

Loading

lukasolson Mar 10, 2021

Dosant Mar 10, 2021

lizozom Mar 11, 2021

kibanamachine commented Mar 11, 2021

Fix search telemetry to only update SO periodically #93130

Fix search telemetry to only update SO periodically #93130

Conversation

lukasolson commented Mar 1, 2021

Summary

elasticmachine commented Mar 1, 2021

lizozom Mar 2, 2021 • edited Loading

Choose a reason for hiding this comment

lukasolson Mar 2, 2021

Choose a reason for hiding this comment

lizozom Mar 2, 2021

Choose a reason for hiding this comment

lukasolson commented Mar 5, 2021

Dosant left a comment

Choose a reason for hiding this comment

Dosant Mar 10, 2021

Choose a reason for hiding this comment

lukasolson Mar 10, 2021

Choose a reason for hiding this comment

Dosant Mar 10, 2021 • edited Loading

Choose a reason for hiding this comment

lukasolson Mar 10, 2021

Choose a reason for hiding this comment

Dosant Mar 10, 2021

Choose a reason for hiding this comment

lizozom Mar 11, 2021

Choose a reason for hiding this comment

kibanamachine commented Mar 11, 2021

💚 Build Succeeded

Metrics [docs]

History

lizozom Mar 2, 2021 •

edited

Loading

Dosant Mar 10, 2021 •

edited

Loading