ES-10037 Periodic logging in autosharding service #126171

PeteGillinElastic · 2025-04-02T19:32:43Z

This enhances DataStreamAutoShardingService so that it periodically logs at INFO level the most 'interesting' results it has produced in the last period.

In this PR, the most 'interesting' results are considered to be the ones with the highest load, keeping track separately of the top 10 which resulting in an increase decision and the top 10 which did not. In practice, increase recommendations are sufficiently rare that the top 10 will often be 'all of them', and they are all potentially interesting (but we cap it to protect against taking up an unbounded amount of memory). We keep the high load non-increase recommendations as well, since these are likely to be the interesting ones to look at when investigating why some data stream did not get an increase shards recommendation when we might have expected it.

The mechanism would be easily extended to add in other categories. For example, we may find that there are some categories of decrease decisions we consider 'interesting'. (N.B. The rollover service will not roll over just because the auto-sharding service recommended down-sharding — down-sharding only happens if the rollover was going to happen for some other reason (age, size, etc.) So it's normal for the auto-sharding service to return decrease recommendations for the same data streams every 5 minutes until those other conditions are met. Which makes things a bit more complicated.) This PR just covers the cases that seem likely to be useful in the support cases we have seen.

The existing DEBUG and TRACE log lines in the service are replaced with a single DEBUG log which pulls together all the data. This is an improvement, since at the moment it is hard to figure out from the logs which lines refer to the same data stream (they are interleaved, and don't all include the data stream name).

The write load field in the AutoShardingResult was unused, and is removed.

PeteGillinElastic · 2025-04-02T19:43:43Z

Hey @dakrone. I'm adding you here to flag it for your attention even though it's in draft — I've slacked you with context.

This enhances DataStreamAutoShardingService so that it periodically logs at INFO level the most 'interesting' results it has produced in the last period. In this PR, the most 'interesting' results are considered to be the ones with the highest load, keeping track separately of the top 10 which resulting in an increase decision and the top 10 which did not. In practice, increase recommendations are sufficiently rare that the top 10 will often be 'all of them', and they are all potentially interesting (but we cap it to protect against taking up an unbounded amount of memory). We keep the high load non-increase recommendations as well, since these are likely to be the interesting ones to look at when investigating why some data stream did not get an increase shards recommendation when we might have expected it. The mechanism would be easily extended to add in other categories. For example, we may find that there are some categories of decrease decisions we consider 'interesting'. (N.B. The rollover service will not roll over just because the auto-sharding service recommended down-sharding — down-sharding only happens if the rollover was going to happen for some other reason (age, size, etc.) So it's normal for the auto-sharding service to return decrease recommendations for the same data streams every 5 minutes until those other conditions are met. Which makes things a bit more complicated.) This PR just covers the cases that seem likely to be useful in the support cases we have seen. The existing DEBUG and TRACE log lines in the service are replaced with a single DEBUG log which pulls together all the data. This is an improvement, since at the moment it is hard to figure out from the logs which lines refer to the same data stream (they are interleaved, and don't all include the data stream name). The write load field in the AutoShardingResult was unused, and is removed.

elasticsearchmachine · 2025-04-03T12:32:20Z

Pinging @elastic/es-data-management (Team:Data Management)

gmarouli

LGTM, I left some minor comments but nothing blocking

gmarouli · 2025-04-04T10:28:27Z

...in/java/org/elasticsearch/action/datastreams/autosharding/DataStreamAutoShardingService.java

    }

-    private AutoShardingResult getDecreaseShardsResult(
+    private Decision.DecreaseCalculation calculateIncreaseShardsDecision(


Probably calculateIncreaseShardsDecision -> calculateDecreaseShardsDecision.

Oh, snap! Good spot. See, I told you that the copy-and-paste errors were my forte...

gmarouli · 2025-04-04T11:44:17Z

...in/java/org/elasticsearch/action/datastreams/autosharding/DataStreamAutoShardingService.java

+        ) {}
+
+        record DecreaseCalculation(
+            MaxLoadWithinCooldown maxLoadWithinCooldownForDecrease,


Nits:

Considering that MaxLoadWithinCooldown is an inner class of DecreaseCalculation, I am wondering if we could change the name to maxLoadWithinCooldown to make it a bit less verbose.

Maybe adding a comment about the previousIndexWithMaxLoad. It's not clear to me when I see this record what it represents. I understand it's an index with max load, but the previous is a bit confusing

Yeah, that's fair enough. For the increase one, I included the extra words at the end of writeIndexLoadForIncrease to differentiate it from the writeIndexLoad* fields in the Inputs record. But it's not really necessary here.

Good point. And I just learnt how to write javadoc on a record, which I'd never had to do before.

…m-autosharding-extra-logging

dakrone

LGTM, I also left some minor comments

dakrone · 2025-04-03T21:38:33Z

...in/java/org/elasticsearch/action/datastreams/autosharding/DataStreamAutoShardingService.java

+        if (decisionLogger == null) {
+            PeriodicDecisionLogger periodicDecisionLogger = new PeriodicDecisionLogger(nowSupplier);
+            this.decisionLogger = periodicDecisionLogger::maybeLogDecision;
+        } else {
+            this.decisionLogger = decisionLogger;
+        }


I don't like the treatment of null as a default of "log the message." I think I'd rather make the constructor take a required non-null argument (with a version that leaves out the argument and passes in the maybeLogDecision method), and then leave it to the caller to override with a no-op if necessary. Otherwise someone would likely assume that they can pass in a null and have the logging disabled.

Yeah, the reason I'd done that was because the naive way of doing the alternative doesn't work, because of the restrictions on what you can do before the this call in a a delegating constructor. I figured it was okay since the constructor with the extra nullable argument is package-private and labelled as for testing, so the scope for misuse was narrow.

But I think I've found a way of doing it with a static method, so I'll do that.

And I've changed the PeriodicLogger constructor to do something similar (only no need for a static method there).

(I guess the alternative would be to junk the public ctor in favour of a static factory method, but this is less invasive of a change.)

dakrone · 2025-04-03T21:39:47Z

...in/java/org/elasticsearch/action/datastreams/autosharding/DataStreamAutoShardingService.java

    }

+    // package-private for testing
+    record Decision(


I think it's useful for these records (this one and its nested children) to document what the fields are, especially since devs may come here not aware of the interior bits of how autoscaling works.

Yeah, Mary already had me put javadoc on one of the records, I might as well do it for the rest...

dakrone · 2025-04-03T21:52:51Z

...in/java/org/elasticsearch/action/datastreams/autosharding/DataStreamAutoShardingService.java

+                "For data stream %s: %s based on [inc/dec cooldowns %s/%s, %d-%d threads, "
+                    + "write index %s has all-time/recent/peak loads %g/%g/%g, current shards %d, "
+                    + "using %s value %g for increase gives %d shards%s]",


While I understand that this log message encapsulates a lot more metrics and info than the previous one, I have to say it's a bit harder to read than "Data stream auto-sharding service recommends increasing the number of shards from [2] to [3] after [5m] cooldown for data stream [logs-foo-bar]". Is it possible to keep the information, but make it a little more user-friendly? (I'm concerned that no one would be able to understand it without knowing details about how data stream autoscaling works, and thus the team would be pulled into SDHs just to decipher the message)

So, the current behaviour is like this: Data stream auto-sharding result: For data stream my-awesome-data-stream: Deferred recommendation to decrease shards from 3 to 2 after cooldown period 5h based on [...]. The nice human-readable bit comes from the toString() I added to AutoShardingResult. I think this is pretty much on a par with the old thing. The information which was present before is all presented in the same order as before and the additional information is at the end. (In fact, I have tweaked it so that it no longer says after [0s] cooldown or whatever in the cases where there's no cooldown, which I argue is a readability improvement.)

If there are further tweaks you'd like to make, let me know!

The thing I quoted above was the debug logging. The periodic info logging looks like this:

Data stream auto-sharding decisions in the last 5m with highest load without an increase shards recommendation: - For data stream my-data-stream: Recommendation to leave shards unchanged at 1 based on [inc/dec cooldowns 4.5m/3d, 2-32 threads, write index .ds-my-data-stream-2025.04.04-000001 has all-time/recent/peak loads 0.000530127/0.000525674/0.00123915, current shards 1, using ALL_TIME value 0.000530127 for increase gives 1 shards, and using ALL_TIME value 0.000530127 for dec based on write index gives 1 shards] - For data stream my-other-data-stream: Recommendation to leave shards unchanged at 1 based on [inc/dec cooldowns 4.5m/3d, 2-32 threads, write index .ds-my-data-stream-2025.04.04-000001 has all-time/recent/peak loads 0.000128001/0.000123547/0.00123915, current shards 1, using ALL_TIME value 0.000128001 for increase gives 1 shards, and using ALL_TIME value 0.000128001 for dec based on write index gives 1 shards]

The … using ALL_TIME value 0.000530127 for dec based on write index gives 1 shards is the most unclear to me, do you think that one could be clarified?

Can you say more about how this is confusing? Is it the ordering of the parts? The use of the abbreviation dec? (I'm conscious of the width of these lines, but that's probably less important than comprehensibility.) Is it that it's not clear that "based on write index" is telling you where that load comes from?

Would decrease calculation gives 3 shards based on PEAK load of 2.71828 for write index be better?

I don't think I can confidently change it without knowing more about the nature of your confusion... Or, even better, you could propose an alternative wording!

I'm running out of time to get this in before I have to leave for the weekend. Unless you say otherwise, I'm going to assume that you don't hate this so much that you can't bear to see it go out into the world, and merge the change which is currently going through CI, and we can wordsmith it in a follow-up PR.

Potential follow-up PR for word-smithing: #126339.

dakrone · 2025-04-04T15:46:48Z

...in/java/org/elasticsearch/action/datastreams/autosharding/DataStreamAutoShardingService.java

+    private static class DecisionBuffer {
+
+        private final Comparator<Decision> comparator;
+        private final PriorityQueue<Decision> queue;


Are you using Lucene's PriorityQueue here only for the insertWithOverflow? Can you add a comment to explain the reasoning so someone doesn't revert it to the JDK version without understanding?

The JDK version isn't bounded. I'll add a comment.

(Based on what I saw on SO, there are people out there who are depending on Lucene just to get their bounded PQ implementation.)

…m-autosharding-extra-logging

PeteGillinElastic · 2025-04-04T16:53:45Z

Thanks @dakrone and @gmarouli . I plan to merge this once it's got through CI, unless you have any more comments.

PeteGillinElastic · 2025-04-04T17:03:28Z

...in/java/org/elasticsearch/action/datastreams/autosharding/DataStreamAutoShardingService.java

+    private static Consumer<Decision> createPeriodicLoggingDecisionConsumer(LongSupplier nowSupplier) {
+        PeriodicDecisionLogger periodicDecisionLogger = new PeriodicDecisionLogger(nowSupplier);
+        return periodicDecisionLogger::maybeLogDecision;
+    }


This static method isn't strictly necessary. It could be inlined as new PeriodicDecisionLogger(nowSupplier)::maybeLogDecision. But I think that's bad readability. If I saw that, it would make me stop and think about what it's doing, and I don't like to have to think.

Also, fun fact, if you write new PeriodicDecisionLogger(nowSupplier)::maybeLogDecision, IntelliJ will offer to "refactor" it into decision -> new PeriodicDecisionLogger(nowSupplier).maybeLogDecision(decision), which would be super bad news. (It does pop up a warning about possible side effects, but still.)

Wow that refactoring (Intellij's) is bad. This static method works for me.

elasticsearchmachine added the v9.1.0 label Apr 2, 2025

PeteGillinElastic requested a review from dakrone April 2, 2025 19:43

PeteGillinElastic force-pushed the ES-10037-data-stream-autosharding-extra-logging branch 4 times, most recently from b290bb9 to cb6e524 Compare April 3, 2025 12:12

PeteGillinElastic force-pushed the ES-10037-data-stream-autosharding-extra-logging branch from cb6e524 to 866aa07 Compare April 3, 2025 12:24

PeteGillinElastic added :Data Management/Data streams Data streams and their lifecycles >non-issue labels Apr 3, 2025

PeteGillinElastic marked this pull request as ready for review April 3, 2025 12:31

elasticsearchmachine added the Team:Data Management Meta label for data/management team label Apr 3, 2025

gmarouli self-requested a review April 4, 2025 11:01

gmarouli approved these changes Apr 4, 2025

View reviewed changes

PeteGillinElastic added 2 commits April 4, 2025 14:57

Respond to comments from Mary

c752e6e

Merge remote-tracking branch 'upstream/main' into ES-10037-data-strea…

58586ee

…m-autosharding-extra-logging

dakrone approved these changes Apr 4, 2025

View reviewed changes

PeteGillinElastic added 2 commits April 4, 2025 17:43

Respond to comments from Lee

7a8a20c

Merge remote-tracking branch 'upstream/main' into ES-10037-data-strea…

56b3d20

…m-autosharding-extra-logging

Typo fix

8a523e5

PeteGillinElastic commented Apr 4, 2025

View reviewed changes

PeteGillinElastic merged commit 78aff25 into elastic:main Apr 4, 2025
17 checks passed

PeteGillinElastic deleted the ES-10037-data-stream-autosharding-extra-logging branch April 4, 2025 18:16

ES-10037 Periodic logging in autosharding service #126171

ES-10037 Periodic logging in autosharding service #126171

Uh oh!

Conversation

PeteGillinElastic commented Apr 2, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

PeteGillinElastic commented Apr 2, 2025

Uh oh!

elasticsearchmachine commented Apr 3, 2025

Uh oh!

gmarouli left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

dakrone left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

PeteGillinElastic Apr 4, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

PeteGillinElastic Apr 4, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

PeteGillinElastic commented Apr 4, 2025

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants

PeteGillinElastic commented Apr 2, 2025 •

edited

Loading

PeteGillinElastic Apr 4, 2025 •

edited

Loading

PeteGillinElastic Apr 4, 2025 •

edited

Loading