path: root/java/com/google/gerrit/server/DeadlineChecker.java

// Copyright (C) 2021 The Android Open Source Project
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
//
// http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.

package com.google.gerrit.server;

import static java.util.Comparator.comparing;
import static java.util.Objects.requireNonNull;
import static java.util.concurrent.TimeUnit.MILLISECONDS;
import static java.util.concurrent.TimeUnit.MINUTES;
import static java.util.concurrent.TimeUnit.NANOSECONDS;
import static java.util.stream.Collectors.toMap;

import com.google.auto.value.AutoValue;
import com.google.common.base.Strings;
import com.google.common.collect.ImmutableList;
import com.google.common.flogger.FluentLogger;
import com.google.common.primitives.Longs;
import com.google.gerrit.common.Nullable;
import com.google.gerrit.server.cancellation.RequestStateProvider;
import com.google.gerrit.server.config.ConfigUtil;
import com.google.gerrit.server.config.GerritServerConfig;
import com.google.gerrit.server.util.time.TimeUtil;
import com.google.inject.assistedinject.Assisted;
import com.google.inject.assistedinject.AssistedInject;
import java.util.HashSet;
import java.util.Map;
import java.util.Optional;
import java.util.Set;
import java.util.concurrent.TimeUnit;
import java.util.function.Function;
import org.eclipse.jgit.lib.Config;

/**
 * {@link RequestStateProvider} that checks whether a client provided deadline is exceeded.
 *
 * <p>Should be registered at most once per request.
 */
public class DeadlineChecker implements RequestStateProvider {
  private static final FluentLogger logger = FluentLogger.forEnclosingClass();

  private static String SECTION_DEADLINE = "deadline";

  /**
   * Creates a formatter that formats a timeout as {@code <TIMEOUT_NAME>=<TIMEOUT><TIME_UNIT>}.
   *
   * <p>If the timeout is 1 minute or greater, minutes is used as a time unit. Otherwise
   * milliseconds is just as a time unit.
   *
   * @param timeoutName the name of the timeout
   */
  public static Function<Long, String> getTimeoutFormatter(String timeoutName) {
    requireNonNull(timeoutName, "timeoutName");
    return timeout -> {
      String formattedTimeout = MILLISECONDS.convert(timeout, NANOSECONDS) + "ms";
      long timeoutInMinutes = MINUTES.convert(timeout, NANOSECONDS);
      if (timeoutInMinutes > 0) {
        formattedTimeout = timeoutInMinutes + "m";
      }
      return String.format("%s=%s", timeoutName, formattedTimeout);
    };
  }

  public interface Factory {
    DeadlineChecker create(RequestInfo requestInfo, @Nullable String clientProvidedTimeoutValue)
        throws InvalidDeadlineException;

    DeadlineChecker create(
        long start, RequestInfo requestInfo, @Nullable String clientProvidedTimeoutValue)
        throws InvalidDeadlineException;
  }

  private final CancellationMetrics cancellationsMetrics;

  /** The start time of the request in nanoseconds. */
  private final long start;

  private final RequestInfo requestInfo;
  private final RequestStateProvider.Reason cancellationReason;
  private final String timeoutName;

  /**
   * Timeout in nanoseconds after which the request should be aborted.
   *
   * <p>{@code 0} means that no timeout should be applied.
   */
  private final long timeout;

  /**
   * The deadline in nanoseconds after which a request should be aborted.
   *
   * <p>deadline = start + timeout
   *
   * <p>{@link Optional#empty()} if no timeout was set.
   */
  private final Optional<Long> deadline;

  /**
   * Matching server side deadlines that have been configured as as advisory.
   *
   * <p>If any of these deadlines is exceeded the request is not be aborted. Instead the {@code
   * cancellation/advisory_deadline_count} metric is incremented and a log is written.
   */
  private final Map<String, ServerDeadline> advisoryDeadlines;

  /**
   * Creates a {@link DeadlineChecker}.
   *
   * <p>No deadline is enforced if the client provided deadline value is {@code null} or {@code 0}.
   *
   * @param requestInfo the request that was received from a user
   * @param clientProvidedTimeoutValue the timeout value that the client provided, must represent a
   *     numerical time unit (e.g. "5m"), if no time unit is specified milliseconds are assumed, may
   *     be {@code null}
   * @throws InvalidDeadlineException thrown if the client provided deadline value cannot be parsed,
   *     e.g. because it uses a bad time unit
   */
  @AssistedInject
  DeadlineChecker(
      @GerritServerConfig Config serverConfig,
      CancellationMetrics cancellationsMetrics,
      @Assisted RequestInfo requestInfo,
      @Assisted @Nullable String clientProvidedTimeoutValue)
      throws InvalidDeadlineException {
    this(
        serverConfig,
        cancellationsMetrics,
        TimeUtil.nowNanos(),
        requestInfo,
        clientProvidedTimeoutValue);
  }

  /**
   * Creates a {@link DeadlineChecker}.
   *
   * <p>No deadline is enforced if the client provided deadline value is {@code null} or {@code 0}.
   *
   * @param start the start time of the request in nanoseconds
   * @param requestInfo the request that was received from a user
   * @param clientProvidedTimeoutValue the timeout value that the client provided, must represent a
   *     numerical time unit (e.g. "5m"), if no time unit is specified milliseconds are assumed, may
   *     be {@code null}
   * @throws InvalidDeadlineException thrown if the client provided deadline value cannot be parsed,
   *     e.g. because it uses a bad time unit
   */
  @AssistedInject
  DeadlineChecker(
      @GerritServerConfig Config serverConfig,
      CancellationMetrics cancellationsMetrics,
      @Assisted long start,
      @Assisted RequestInfo requestInfo,
      @Assisted @Nullable String clientProvidedTimeoutValue)
      throws InvalidDeadlineException {
    this.cancellationsMetrics = cancellationsMetrics;
    this.start = start;
    this.requestInfo = requestInfo;

    ImmutableList<RequestConfig> deadlineConfigs =
        RequestConfig.parseConfigs(serverConfig, SECTION_DEADLINE);
    advisoryDeadlines = getAdvisoryDeadlines(deadlineConfigs, requestInfo);
    Optional<ServerDeadline> serverSideDeadline =
        getServerSideDeadline(deadlineConfigs, requestInfo);
    Optional<Long> clientedProvidedTimeout = parseTimeout(clientProvidedTimeoutValue);
    logDeadlines(serverSideDeadline, clientedProvidedTimeout);

    this.cancellationReason =
        clientedProvidedTimeout.isPresent()
            ? RequestStateProvider.Reason.CLIENT_PROVIDED_DEADLINE_EXCEEDED
            : RequestStateProvider.Reason.SERVER_DEADLINE_EXCEEDED;
    this.timeoutName =
        clientedProvidedTimeout
            .map(clientTimeout -> "client.timeout")
            .orElseGet(
                () ->
                    serverSideDeadline
                        .map(serverDeadline -> serverDeadline.id() + ".timeout")
                        .orElse("timeout"));
    this.timeout =
        clientedProvidedTimeout.orElseGet(
            () -> serverSideDeadline.map(ServerDeadline::timeout).orElse(0L));
    this.deadline = timeout > 0 ? Optional.of(start + timeout) : Optional.empty();
  }

  private void logDeadlines(
      Optional<ServerDeadline> serverSideDeadline, Optional<Long> clientedProvidedTimeout) {
    if (serverSideDeadline.isPresent()) {
      if (clientedProvidedTimeout.isPresent()) {
        logger.atFine().log(
            "client provided deadline (timeout=%sms) overrides server deadline %s (timeout=%sms)",
            TimeUnit.MILLISECONDS.convert(clientedProvidedTimeout.get(), TimeUnit.NANOSECONDS),
            serverSideDeadline.get().id(),
            TimeUnit.MILLISECONDS.convert(
                serverSideDeadline.get().timeout(), TimeUnit.NANOSECONDS));
      } else {
        logger.atFine().log(
            "applying server deadline %s (timeout = %sms)",
            serverSideDeadline.get().id(),
            TimeUnit.MILLISECONDS.convert(
                serverSideDeadline.get().timeout(), TimeUnit.NANOSECONDS));
      }
    } else if (clientedProvidedTimeout.isPresent()) {
      logger.atFine().log(
          "applying client provided deadline (timeout = %sms)",
          TimeUnit.MILLISECONDS.convert(clientedProvidedTimeout.get(), TimeUnit.NANOSECONDS));
    }
  }

  private Optional<ServerDeadline> getServerSideDeadline(
      ImmutableList<RequestConfig> deadlineConfigs, RequestInfo requestInfo) {
    return deadlineConfigs.stream()
        .filter(deadlineConfig -> deadlineConfig.matches(requestInfo))
        .map(ServerDeadline::readFrom)
        .filter(ServerDeadline::hasTimeout)
        .filter(deadline -> !deadline.isAdvisory())
        // let the stricter deadline (the lower deadline) take precedence
        .sorted(comparing(ServerDeadline::timeout))
        .findFirst();
  }

  private Map<String, ServerDeadline> getAdvisoryDeadlines(
      ImmutableList<RequestConfig> deadlineConfigs, RequestInfo requestInfo) {
    return deadlineConfigs.stream()
        .filter(deadlineConfig -> deadlineConfig.matches(requestInfo))
        .map(ServerDeadline::readFrom)
        .filter(ServerDeadline::hasTimeout)
        .filter(ServerDeadline::isAdvisory)
        .collect(toMap(ServerDeadline::id, Function.identity()));
  }

  @Override
  public void checkIfCancelled(OnCancelled onCancelled) {
    long now = TimeUtil.nowNanos();

    Set<String> exceededAdvisoryDeadlines = new HashSet<>();
    advisoryDeadlines
        .values()
        .forEach(
            advisoryDeadline -> {
              if (now > start + advisoryDeadline.timeout()) {
                exceededAdvisoryDeadlines.add(advisoryDeadline.id());
                logger.atFine().log(
                    "advisory deadline exceeded (%s)",
                    getTimeoutFormatter(advisoryDeadline.id() + ".timeout")
                        .apply(advisoryDeadline.timeout()));
                cancellationsMetrics.countAdvisoryDeadline(requestInfo, advisoryDeadline.id());
              }
            });
    // remove advisory deadlines which have already been reported as exceeded so that they don't get
    // reported again for this request
    exceededAdvisoryDeadlines.forEach(advisoryDeadlines::remove);

    if (deadline.isPresent() && now > deadline.get()) {
      onCancelled.onCancel(cancellationReason, getTimeoutFormatter(timeoutName).apply(timeout));
    }
  }

  /**
   * Parses the given timeout value.
   *
   * @param timeoutValue the timeout that should be parsed, must represent a numerical time unit
   *     (e.g. "5m"), if no time unit is specified minutes are assumed, may be {@code null}
   * @return the parsed timeout in nanoseconds, {@code 0} if no timeout should be applied
   * @throws InvalidDeadlineException thrown if the provided deadline value cannot be parsed, e.g.
   *     because it uses a bad time unit
   */
  private static Optional<Long> parseTimeout(@Nullable String timeoutValue)
      throws InvalidDeadlineException {
    if (Strings.isNullOrEmpty(timeoutValue)) {
      return Optional.empty();
    }

    if ("0".equals(timeoutValue)) {
      return Optional.of(0L);
    }

    // If no time unit was specified, assume milliseconds.
    if (Longs.tryParse(timeoutValue) != null) {
      throw new InvalidDeadlineException(String.format("Missing time unit: %s", timeoutValue));
    }

    try {
      long parsedTimeout =
          ConfigUtil.getTimeUnit(timeoutValue, /* defaultValue= */ -1, TimeUnit.NANOSECONDS);
      if (parsedTimeout == -1) {
        throw new InvalidDeadlineException(String.format("Invalid value: %s", timeoutValue));
      }
      return Optional.of(parsedTimeout);
    } catch (IllegalArgumentException e) {
      throw new InvalidDeadlineException(e.getMessage(), e);
    }
  }

  @AutoValue
  abstract static class ServerDeadline {
    abstract String id();

    abstract long timeout();

    abstract boolean isAdvisory();

    boolean hasTimeout() {
      return timeout() > 0;
    }

    static ServerDeadline readFrom(RequestConfig requestConfig) {
      String timeoutValue =
          requestConfig.cfg().getString(requestConfig.section(), requestConfig.id(), "timeout");
      boolean isAdvisory =
          requestConfig
              .cfg()
              .getBoolean(
                  requestConfig.section(),
                  requestConfig.id(),
                  "isAdvisory",
                  /* defaultValue= */ false);
      try {
        Optional<Long> timeout = parseTimeout(timeoutValue);
        return new AutoValue_DeadlineChecker_ServerDeadline(
            requestConfig.id(), timeout.orElse(0L), isAdvisory);
      } catch (InvalidDeadlineException e) {
        logger.atWarning().log(
            "Ignoring invalid deadline configuration %s.%s.timeout: %s",
            requestConfig.section(), requestConfig.id(), e.getMessage());
        return new AutoValue_DeadlineChecker_ServerDeadline(requestConfig.id(), 0, isAdvisory);
      }
    }
  }
}