Skip to content

Commit

Permalink
Remove logic that increases delay between progress updates over time
Browse files Browse the repository at this point in the history
Removes a bit of undocumented behavior that increases the delay between progress updates the longer the build is running.
Potentially resolves bazelbuild#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 bazelbuild#16119.

Closes bazelbuild#16221.

RELNOTES[INC]: Bazel no longer increases the delay between progress updates when there is no cursor control.

PiperOrigin-RevId: 484203851
Change-Id: I33f7302ca85b75135744eb6093b618196199a49f
  • Loading branch information
tom-cnops authored and copybara-github committed Oct 27, 2022
1 parent c9f9b0b commit a706994
Show file tree
Hide file tree
Showing 3 changed files with 28 additions and 40 deletions.
12 changes: 7 additions & 5 deletions site/en/docs/user-manual.md
Original file line number Diff line number Diff line change
Expand Up @@ -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 {{ "<var>" }}resources or resource expression{{ "</var>" }}` {:#local-resources}

These options specify the amount of local resources (RAM in MB and number of CPU logical cores)
Expand Down Expand Up @@ -1129,11 +1132,10 @@ default. When disabled, progress messages are suppressed.

#### `--show_progress_rate_limit={{ "<var>" }}n{{ "</var>" }}` {:#show-progress-rate}

This option causes bazel to display only
one progress message per `n` seconds, where {{ "<var>" }}n{{ "</var>" }} 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 {{ "<var>" }}n{{ "</var>" }} 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={{ "<var>" }}n{{ "</var>" }}` {:#show-result}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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(
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -81,27 +81,19 @@ 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) ");
private static final DateTimeFormatter DATE_FORMAT = DateTimeFormatter.ofPattern("yyyy-MM-dd");

private final boolean cursorControl;
private final Clock clock;
private final long uiStartTimeMillis;
private final AnsiTerminal terminal;
private final boolean debugAllEvents;
private final UiStateTracker stateTracker;
Expand All @@ -111,7 +103,7 @@ public final class UiEventHandler implements EventHandler {
private final boolean showTimestamp;
private final OutErr outErr;
private final ImmutableSet<EventKind> filteredEvents;
private long minimalDelayMillis;
private long progressRateLimitMillis;
private long minimalUpdateInterval;
private long lastRefreshMillis;
private long mustRefreshAfterMillis;
Expand Down Expand Up @@ -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);
Expand All @@ -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;
Expand Down Expand Up @@ -854,7 +846,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) {
Expand All @@ -863,17 +855,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) {
Expand Down Expand Up @@ -901,7 +882,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();
}
Expand All @@ -911,22 +892,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() {
Expand Down

0 comments on commit a706994

Please sign in to comment.