From 60e9bf339f319d16b738619a05b1dd5d122ef852 Mon Sep 17 00:00:00 2001
From: kshyanashree <109167932+kshyanashree@users.noreply.github.com>
Date: Fri, 28 Oct 2022 09:53:24 -0700
Subject: [PATCH] Remove logic that increases delay between progress updates
over time (#16606)
Removes a bit of undocumented behavior that increases the delay between progress updates the longer the build is running.
Potentially resolves https://github.com/bazelbuild/bazel/issues/16119
Also renamed `MAXIMAL_UPDATE_DELAY_MILLIS` to `MINIMAL_UPDATE_INTERVAL_MILLIS` because it is used as a minimum and doesn't affect the delay between messages.
Fixes #16119.
Closes #16221.
RELNOTES[INC]: Bazel no longer increases the delay between progress updates when there is no cursor control.
PiperOrigin-RevId: 484203851
Change-Id: I33f7302ca85b75135744eb6093b618196199a49f
Co-authored-by: Tom Cnops <60213975+tom-cnops@users.noreply.github.com>
---
site/en/docs/user-manual.md | 12 +++--
.../lib/buildtool/BuildRequestOptions.java | 6 ++-
.../build/lib/runtime/UiEventHandler.java | 50 +++++++------------
3 files changed, 28 insertions(+), 40 deletions(-)
diff --git a/site/en/docs/user-manual.md b/site/en/docs/user-manual.md
index e4f0afe960a16f..4b81b26d29ec4e 100644
--- a/site/en/docs/user-manual.md
+++ b/site/en/docs/user-manual.md
@@ -790,6 +790,9 @@ The default is 0, that means an incremental algorithm: the first
report will be printed after 10 seconds, then 30 seconds and after
that progress is reported once every minute.
+When bazel is using cursor control, as specified by
+[`--curses`](#curses), progress is reported every second.
+
#### `--local_{ram,cpu}_resources {{ "" }}resources or resource expression{{ "" }}` {:#local-resources}
These options specify the amount of local resources (RAM in MB and number of CPU logical cores)
@@ -1126,11 +1129,10 @@ default. When disabled, progress messages are suppressed.
#### `--show_progress_rate_limit={{ "" }}n{{ "" }}` {:#show-progress-rate}
-This option causes bazel to display only
-one progress message per `n` seconds, where {{ "" }}n{{ "" }} is a real number.
-If `n` is -1, all progress messages will be displayed. The default value for
-this option is 0.02, meaning bazel will limit the progress messages to one per every
-0.02 seconds.
+This option causes bazel to display at most one progress message per `n` seconds,
+where {{ "" }}n{{ "" }} is a real number.
+The default value for this option is 0.02, meaning bazel will limit the progress
+messages to one per every 0.02 seconds.
#### `--show_result={{ "" }}n{{ "" }}` {:#show-result}
diff --git a/src/main/java/com/google/devtools/build/lib/buildtool/BuildRequestOptions.java b/src/main/java/com/google/devtools/build/lib/buildtool/BuildRequestOptions.java
index 3db5ed194fc6a0..5b9b24f3e88b56 100644
--- a/src/main/java/com/google/devtools/build/lib/buildtool/BuildRequestOptions.java
+++ b/src/main/java/com/google/devtools/build/lib/buildtool/BuildRequestOptions.java
@@ -73,8 +73,10 @@ public class BuildRequestOptions extends OptionsBase {
effectTags = {OptionEffectTag.AFFECTS_OUTPUTS},
converter = ProgressReportIntervalConverter.class,
help =
- "The number of seconds to wait between two reports on still running jobs. The "
- + "default value 0 means to use the default 10:30:60 incremental algorithm.")
+ "The number of seconds to between reports on still running jobs. The "
+ + "default value 0 means the first report will be printed after 10 "
+ + "seconds, then 30 seconds and after that progress is reported once every minute. "
+ + "When --curses is enabled, progress is reported every second.")
public int progressReportInterval;
@Option(
diff --git a/src/main/java/com/google/devtools/build/lib/runtime/UiEventHandler.java b/src/main/java/com/google/devtools/build/lib/runtime/UiEventHandler.java
index 21e625280a273f..eb59e4fe4e0c42 100644
--- a/src/main/java/com/google/devtools/build/lib/runtime/UiEventHandler.java
+++ b/src/main/java/com/google/devtools/build/lib/runtime/UiEventHandler.java
@@ -81,19 +81,12 @@ public final class UiEventHandler implements EventHandler {
private static final GoogleLogger logger = GoogleLogger.forEnclosingClass();
- /** Latest refresh of the progress bar, if contents other than time changed */
- private static final long MAXIMAL_UPDATE_DELAY_MILLIS = 200L;
+ /** Minimal time between scheduled updates */
+ private static final long MINIMAL_UPDATE_INTERVAL_MILLIS = 200L;
/** Minimal rate limiting (in ms), if the progress bar cannot be updated in place */
private static final long NO_CURSES_MINIMAL_PROGRESS_RATE_LIMIT = 1000L;
- /**
- * Minimal rate limiting, as fraction of the request time so far, if the progress bar cannot be
- * updated in place
- */
- private static final double NO_CURSES_MINIMAL_RELATIVE_PROGRESS_RATE_LMIT = 0.15;
/** Periodic update interval of a time-dependent progress bar if it can be updated in place */
private static final long SHORT_REFRESH_MILLIS = 1000L;
- /** Periodic update interval of a time-dependent progress bar if it cannot be updated in place */
- private static final long LONG_REFRESH_MILLIS = 20000L;
private static final DateTimeFormatter TIMESTAMP_FORMAT =
DateTimeFormatter.ofPattern("(HH:mm:ss) ");
@@ -101,7 +94,6 @@ public final class UiEventHandler implements EventHandler {
private final boolean cursorControl;
private final Clock clock;
- private final long uiStartTimeMillis;
private final AnsiTerminal terminal;
private final boolean debugAllEvents;
private final UiStateTracker stateTracker;
@@ -111,7 +103,7 @@ public final class UiEventHandler implements EventHandler {
private final boolean showTimestamp;
private final OutErr outErr;
private final ImmutableSet filteredEvents;
- private long minimalDelayMillis;
+ private long progressRateLimitMillis;
private long minimalUpdateInterval;
private long lastRefreshMillis;
private long mustRefreshAfterMillis;
@@ -175,7 +167,6 @@ public UiEventHandler(
this.progressInTermTitle = options.progressInTermTitle && options.useCursorControl();
this.showTimestamp = options.showTimestamp;
this.clock = clock;
- this.uiStartTimeMillis = clock.currentTimeMillis();
this.debugAllEvents = options.experimentalUiDebugAllEvents;
this.locationPrinter =
new LocationPrinter(options.attemptToPrintRelativePaths, workspacePathFragment);
@@ -200,14 +191,15 @@ public UiEventHandler(
this.stateTracker.setProgressSampleSize(options.uiActionsShown);
this.numLinesProgressBar = 0;
if (this.cursorControl) {
- this.minimalDelayMillis = Math.round(options.showProgressRateLimit * 1000);
+ this.progressRateLimitMillis = Math.round(options.showProgressRateLimit * 1000);
} else {
- this.minimalDelayMillis =
+ this.progressRateLimitMillis =
Math.max(
Math.round(options.showProgressRateLimit * 1000),
NO_CURSES_MINIMAL_PROGRESS_RATE_LIMIT);
}
- this.minimalUpdateInterval = Math.max(this.minimalDelayMillis, MAXIMAL_UPDATE_DELAY_MILLIS);
+ this.minimalUpdateInterval =
+ Math.max(this.progressRateLimitMillis, MINIMAL_UPDATE_INTERVAL_MILLIS);
this.stdoutLineBuffer = new ByteArrayOutputStream();
this.stderrLineBuffer = new ByteArrayOutputStream();
this.dateShown = false;
@@ -852,7 +844,7 @@ private void doRefresh(boolean fromUpdateThread) {
return;
}
long nowMillis = clock.currentTimeMillis();
- if (lastRefreshMillis + minimalDelayMillis < nowMillis) {
+ if (lastRefreshMillis + progressRateLimitMillis < nowMillis) {
if (updateLock.tryLock()) {
try {
synchronized (this) {
@@ -861,17 +853,6 @@ private void doRefresh(boolean fromUpdateThread) {
clearProgressBar();
addProgressBar();
terminal.flush();
- if (!cursorControl) {
- // If we can't update the progress bar in place, make sure we increase the update
- // interval as time progresses, to avoid too many progress messages in place.
- minimalDelayMillis =
- Math.max(
- minimalDelayMillis,
- Math.round(
- NO_CURSES_MINIMAL_RELATIVE_PROGRESS_RATE_LMIT
- * (clock.currentTimeMillis() - uiStartTimeMillis)));
- minimalUpdateInterval = Math.max(minimalDelayMillis, MAXIMAL_UPDATE_DELAY_MILLIS);
- }
}
}
} catch (IOException e) {
@@ -899,7 +880,7 @@ private void refreshSoon() {
// a future update scheduled.
long nowMillis = clock.currentTimeMillis();
if (mustRefreshAfterMillis <= lastRefreshMillis) {
- mustRefreshAfterMillis = Math.max(nowMillis + minimalUpdateInterval, lastRefreshMillis + 1);
+ mustRefreshAfterMillis = Math.max(nowMillis + 1, lastRefreshMillis + minimalUpdateInterval);
}
startUpdateThread();
}
@@ -909,22 +890,25 @@ private synchronized boolean timeBasedRefresh() {
if (!stateTracker.progressBarTimeDependent()) {
return false;
}
+ // Don't do more updates than are requested through events when there is no cursor control.
+ if (!cursorControl) {
+ return false;
+ }
long nowMillis = clock.currentTimeMillis();
- long intervalMillis = cursorControl ? SHORT_REFRESH_MILLIS : LONG_REFRESH_MILLIS;
if (lastRefreshMillis < mustRefreshAfterMillis
- && mustRefreshAfterMillis < nowMillis + minimalDelayMillis) {
- // Within the small interval from now, an update is scheduled anyway,
+ && mustRefreshAfterMillis < nowMillis + progressRateLimitMillis) {
+ // Within a small interval from now, an update is scheduled anyway,
// so don't do a time-based update of the progress bar now, to avoid
// updates too close to each other.
return false;
}
- return lastRefreshMillis + intervalMillis < nowMillis;
+ return lastRefreshMillis + SHORT_REFRESH_MILLIS < nowMillis;
}
private void ignoreRefreshLimitOnce() {
// Set refresh time variables in a state such that the next progress bar
// update will definitely be written out.
- lastRefreshMillis = clock.currentTimeMillis() - minimalDelayMillis - 1;
+ lastRefreshMillis = clock.currentTimeMillis() - progressRateLimitMillis - 1;
}
private void startUpdateThread() {