Add logging for parked tasks
Log task parking events with quota details for better debugging.
Centralize quota logging in quota.log file
Change-Id: If313ec184a8c6a6f603ca431d58a458dbed2e0d0
diff --git a/src/main/java/com/googlesource/gerrit/plugins/quota/MinStartForQueueQuota.java b/src/main/java/com/googlesource/gerrit/plugins/quota/MinStartForQueueQuota.java
index 33b9a3f..68cdc1d 100644
--- a/src/main/java/com/googlesource/gerrit/plugins/quota/MinStartForQueueQuota.java
+++ b/src/main/java/com/googlesource/gerrit/plugins/quota/MinStartForQueueQuota.java
@@ -14,15 +14,15 @@
package com.googlesource.gerrit.plugins.quota;
-import org.slf4j.Logger;
-import org.slf4j.LoggerFactory;
-
import java.util.Optional;
import java.util.regex.Matcher;
import java.util.regex.Pattern;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
public class MinStartForQueueQuota {
public static final Logger log = LoggerFactory.getLogger(MinStartForQueueQuota.class);
+ public static final String KEY = "minStartForQueue";
// 10 SSH-Interactive-Worker
public static final Pattern CONFIG_PATTERN = Pattern.compile("(\\d+)\\s+(.+)");
@@ -35,16 +35,17 @@
}
if (matcher.matches()) {
- int limit = Integer.parseInt(matcher.group(1));
+ int reservation = Integer.parseInt(matcher.group(1));
String queue = matcher.group(2);
QueueManager.registerReservation(
queue,
new QueueManager.Reservation(
- limit,
+ reservation,
task -> {
return task.getQueueName().equalsIgnoreCase(queue)
&& TaskQuotas.estimateProject(task).map(qs::matches).orElse(false);
- }));
+ },
+ qs.getNamespace()));
} else {
log.error("Invalid configuration entry [{}]", cfg);
}
diff --git a/src/main/java/com/googlesource/gerrit/plugins/quota/Module.java b/src/main/java/com/googlesource/gerrit/plugins/quota/Module.java
index 781787a..045801f 100644
--- a/src/main/java/com/googlesource/gerrit/plugins/quota/Module.java
+++ b/src/main/java/com/googlesource/gerrit/plugins/quota/Module.java
@@ -96,6 +96,9 @@
bind(LifecycleListener.class)
.annotatedWith(UniqueAnnotations.create())
.to(PublisherScheduler.class);
+ bind(LifecycleListener.class)
+ .annotatedWith(UniqueAnnotations.create())
+ .to(TaskQuotaLogFile.class);
DynamicSet.bind(binder(), UploadValidationListener.class).to(RateLimitUploadListener.class);
bindConstant()
diff --git a/src/main/java/com/googlesource/gerrit/plugins/quota/ParkedQuotaTransitionLogger.java b/src/main/java/com/googlesource/gerrit/plugins/quota/ParkedQuotaTransitionLogger.java
new file mode 100644
index 0000000..bb40a19
--- /dev/null
+++ b/src/main/java/com/googlesource/gerrit/plugins/quota/ParkedQuotaTransitionLogger.java
@@ -0,0 +1,91 @@
+// Copyright (C) 2025 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.googlesource.gerrit.plugins.quota;
+
+import static com.google.gerrit.server.git.WorkQueue.Task;
+import static com.googlesource.gerrit.plugins.quota.QueueManager.Queue;
+import static com.googlesource.gerrit.plugins.quota.QueueManager.QueueInfo;
+import static com.googlesource.gerrit.plugins.quota.QueueManager.Reservation;
+
+import com.google.gerrit.util.logging.NamedFluentLogger;
+import java.util.Map;
+import java.util.Optional;
+import java.util.concurrent.ConcurrentHashMap;
+import java.util.function.Supplier;
+import java.util.stream.Collectors;
+
+public class ParkedQuotaTransitionLogger {
+ protected static final NamedFluentLogger quotaLog =
+ NamedFluentLogger.forName(TaskQuotaLogFile.NAME);
+ protected static final Map<Integer, TaskQuota> prevParkingQuotaByTaskId =
+ new ConcurrentHashMap<>();
+ protected static final TaskQuota CANNOT_SATISFY_RESERVATIONS_QUOTA =
+ new TaskQuota() {
+ @Override
+ public boolean isApplicable(Task<?> task) {
+ throw new IllegalStateException();
+ }
+
+ @Override
+ public boolean isReadyToStart(Task<?> task) {
+ throw new IllegalStateException();
+ }
+
+ @Override
+ public void onStop(Task<?> task) {
+ throw new IllegalStateException();
+ }
+ };
+
+ /** Logs only if the reason for parked changes from the previous parking event. */
+ public static void logTaskWithEnforcedQuota(Task<?> t, TaskQuota q) {
+ if (shouldLog(t, q)) {
+ quotaLog.atInfo().log("Task [%s] parked due to quota rule [%s]", t, q);
+ }
+ }
+
+ public static void logTaskWithNoSatisfyingReservation(Task<?> t) {
+ if (!shouldLog(t, CANNOT_SATISFY_RESERVATIONS_QUOTA)) {
+ return;
+ }
+
+ QueueInfo queueInfo = QueueManager.infoByQueue.get(Queue.fromKey(t.getQueueName()));
+ if (queueInfo != null) {
+ queueInfo.reservations.stream()
+ .filter(r -> r.matches(t))
+ .findFirst()
+ .ifPresentOrElse(
+ reservation -> {
+ quotaLog.atInfo().log(
+ "Task [%s] parked because there are no spare unreserved threads in queue [%s], "
+ + "and there are insufficient reserved threads for the %s namespace",
+ t, t.getQueueName(), reservation.namespace());
+ },
+ () -> {
+ quotaLog.atInfo().log(
+ "Task [%s] parked because there are no spare unreserved threads in queue [%s]",
+ t, t.getQueueName());
+ });
+ }
+ }
+
+ public static boolean shouldLog(Task<?> t, TaskQuota q) {
+ return prevParkingQuotaByTaskId.put(t.getTaskId(), q) != q;
+ }
+
+ public static void clear(Task<?> t) {
+ prevParkingQuotaByTaskId.remove(t.getTaskId());
+ }
+}
diff --git a/src/main/java/com/googlesource/gerrit/plugins/quota/QueueManager.java b/src/main/java/com/googlesource/gerrit/plugins/quota/QueueManager.java
index 4b0010d..dc6d658 100644
--- a/src/main/java/com/googlesource/gerrit/plugins/quota/QueueManager.java
+++ b/src/main/java/com/googlesource/gerrit/plugins/quota/QueueManager.java
@@ -15,19 +15,18 @@
package com.googlesource.gerrit.plugins.quota;
import com.google.gerrit.server.git.WorkQueue;
-import org.slf4j.Logger;
-import org.slf4j.LoggerFactory;
-
+import java.util.*;
import java.util.ArrayList;
import java.util.Arrays;
import java.util.List;
import java.util.Map;
import java.util.concurrent.ConcurrentHashMap;
-import java.util.function.Predicate;
-
-import java.util.*;
import java.util.concurrent.ConcurrentMap;
import java.util.concurrent.atomic.AtomicBoolean;
+import java.util.function.Predicate;
+import java.util.function.Supplier;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
public class QueueManager {
public static final Logger log = LoggerFactory.getLogger(QueueManager.class);
@@ -101,7 +100,8 @@
}
}
- public record Reservation(int reservedCapacity, Predicate<WorkQueue.Task<?>> taskMatcher) {
+ public record Reservation(
+ int reservedCapacity, Predicate<WorkQueue.Task<?>> taskMatcher, String namespace) {
public boolean matches(WorkQueue.Task<?> task) {
return taskMatcher.test(task);
}
@@ -164,7 +164,8 @@
qName,
reservation.reservedCapacity(),
capacityToReserve);
- queueInfo.addReservation(new Reservation(capacityToReserve, reservation.taskMatcher));
+ queueInfo.addReservation(
+ new Reservation(capacityToReserve, reservation.taskMatcher, reservation.namespace()));
return;
}
diff --git a/src/main/java/com/googlesource/gerrit/plugins/quota/SoftMaxPerUserForQueue.java b/src/main/java/com/googlesource/gerrit/plugins/quota/SoftMaxPerUserForQueue.java
index de7c630..19fa018 100644
--- a/src/main/java/com/googlesource/gerrit/plugins/quota/SoftMaxPerUserForQueue.java
+++ b/src/main/java/com/googlesource/gerrit/plugins/quota/SoftMaxPerUserForQueue.java
@@ -24,14 +24,17 @@
import java.util.regex.Pattern;
public class SoftMaxPerUserForQueue implements TaskQuota {
+ public static final String KEY = "softMaxStartPerUserForQueue";
public static final Pattern CONFIG_PATTERN =
Pattern.compile("(\\d+)\\s+(" + String.join("|", QueueManager.Queue.keys()) + ")");
+ private final QuotaSection quotaSection;
private final int softMax;
private final QueueManager.Queue queue;
private final ConcurrentHashMap<String, Integer> taskStartedCountByUser =
new ConcurrentHashMap<>();
- public SoftMaxPerUserForQueue(int softMax, String queueName) {
+ public SoftMaxPerUserForQueue(QuotaSection quotaSection, int softMax, String queueName) {
+ this.quotaSection = quotaSection;
this.softMax = softMax;
this.queue = QueueManager.Queue.fromKey(queueName);
}
@@ -79,7 +82,14 @@
Matcher matcher = CONFIG_PATTERN.matcher(cfg);
return matcher.find()
? Optional.of(
- new SoftMaxPerUserForQueue(Integer.parseInt(matcher.group(1)), matcher.group(2)))
+ new SoftMaxPerUserForQueue(qs, Integer.parseInt(matcher.group(1)), matcher.group(2)))
: Optional.empty();
}
+
+ @Override
+ public String toString() {
+ return KEY
+ + ": softMax [%d], queue [%s], namespace [%s]"
+ .formatted(softMax, queue.getName(), quotaSection.getNamespace());
+ }
}
diff --git a/src/main/java/com/googlesource/gerrit/plugins/quota/TaskQuotaForTask.java b/src/main/java/com/googlesource/gerrit/plugins/quota/TaskQuotaForTask.java
index 2d15abe..8375c3b 100644
--- a/src/main/java/com/googlesource/gerrit/plugins/quota/TaskQuotaForTask.java
+++ b/src/main/java/com/googlesource/gerrit/plugins/quota/TaskQuotaForTask.java
@@ -21,7 +21,7 @@
public abstract class TaskQuotaForTask extends TaskQuotaWithPermits {
protected static final Map<String, Set<String>> SUPPORTED_TASKS_BY_GROUP =
Map.of("uploadpack", Set.of("git-upload-pack"), "receivepack", Set.of("git-receive-pack"));
- private final String taskGroup;
+ public final String taskGroup;
public TaskQuotaForTask(String taskGroup, int permits) {
super(permits);
diff --git a/src/main/java/com/googlesource/gerrit/plugins/quota/TaskQuotaForTaskForQueue.java b/src/main/java/com/googlesource/gerrit/plugins/quota/TaskQuotaForTaskForQueue.java
index ac57a00..535edbf 100644
--- a/src/main/java/com/googlesource/gerrit/plugins/quota/TaskQuotaForTaskForQueue.java
+++ b/src/main/java/com/googlesource/gerrit/plugins/quota/TaskQuotaForTaskForQueue.java
@@ -23,13 +23,17 @@
public class TaskQuotaForTaskForQueue extends TaskQuotaForTask {
public static final Logger log = LoggerFactory.getLogger(TaskQuotaForTaskForQueue.class);
+ public static final String KEY = "maxStartForTaskForQueue";
public static final Pattern CONFIG_PATTERN =
Pattern.compile(
"(\\d+)\\s+(" + String.join("|", SUPPORTED_TASKS_BY_GROUP.keySet()) + ")\\s+(.+)");
- private final String queueName;
+ public final String queueName;
+ protected final QuotaSection quotaSection;
- public TaskQuotaForTaskForQueue(String queueName, String taskGroup, int maxStart) {
+ public TaskQuotaForTaskForQueue(
+ QuotaSection quotaSection, String queueName, String taskGroup, int maxStart) {
super(taskGroup, maxStart);
+ this.quotaSection = quotaSection;
this.queueName = queueName;
}
@@ -43,10 +47,17 @@
if (matcher.matches()) {
return Optional.of(
new TaskQuotaForTaskForQueue(
- matcher.group(3), matcher.group(2), Integer.parseInt(matcher.group(1))));
+ qs, matcher.group(3), matcher.group(2), Integer.parseInt(matcher.group(1))));
} else {
log.error("Invalid configuration entry [{}]", cfg);
return Optional.empty();
}
}
+
+ @Override
+ public String toString() {
+ return KEY
+ + ": task [%s], queue [%s], permits [%d], namespace [%s]"
+ .formatted(taskGroup, queueName, maxPermits, quotaSection.getNamespace());
+ }
}
diff --git a/src/main/java/com/googlesource/gerrit/plugins/quota/TaskQuotaForTaskForQueueForUser.java b/src/main/java/com/googlesource/gerrit/plugins/quota/TaskQuotaForTaskForQueueForUser.java
index 7afa870..751559e 100644
--- a/src/main/java/com/googlesource/gerrit/plugins/quota/TaskQuotaForTaskForQueueForUser.java
+++ b/src/main/java/com/googlesource/gerrit/plugins/quota/TaskQuotaForTaskForQueueForUser.java
@@ -23,6 +23,7 @@
public class TaskQuotaForTaskForQueueForUser extends TaskQuotaForTaskForQueue {
public static final Logger log = LoggerFactory.getLogger(TaskQuotaForTaskForQueueForUser.class);
+ public static final String KEY = "maxStartForTaskForUserForQueue";
public static final Pattern CONFIG_PATTERN =
Pattern.compile(
"(\\d+)\\s+("
@@ -33,8 +34,8 @@
private final String user;
public TaskQuotaForTaskForQueueForUser(
- String queueName, String user, String taskGroup, int maxStart) {
- super(queueName, taskGroup, maxStart);
+ QuotaSection quotaSection, String queueName, String user, String taskGroup, int maxStart) {
+ super(quotaSection, queueName, taskGroup, maxStart);
this.user = user;
}
@@ -49,6 +50,7 @@
if (matcher.matches()) {
return Optional.of(
new TaskQuotaForTaskForQueueForUser(
+ qs,
matcher.group(4),
matcher.group(3),
matcher.group(2),
@@ -58,4 +60,11 @@
return Optional.empty();
}
}
+
+ @Override
+ public String toString() {
+ return KEY
+ + ": task [%s], queue [%s], user [%s], permits [%d], namespace [%s]"
+ .formatted(taskGroup, queueName, user, maxPermits, quotaSection.getNamespace());
+ }
}
diff --git a/src/main/java/com/googlesource/gerrit/plugins/quota/TaskQuotaKeys.java b/src/main/java/com/googlesource/gerrit/plugins/quota/TaskQuotaKeys.java
index ff0a4cb..65da2a5 100644
--- a/src/main/java/com/googlesource/gerrit/plugins/quota/TaskQuotaKeys.java
+++ b/src/main/java/com/googlesource/gerrit/plugins/quota/TaskQuotaKeys.java
@@ -18,13 +18,13 @@
import java.util.function.BiFunction;
public enum TaskQuotaKeys {
- MAX_START_FOR_TASK_FOR_QUEUE("maxStartForTaskForQueue", TaskQuotaForTaskForQueue::build),
- MIN_START_FOR_TASK_FOR_QUEUE("minStartForQueue", MinStartForQueueQuota::build),
+ MAX_START_FOR_TASK_FOR_QUEUE(TaskQuotaForTaskForQueue.KEY, TaskQuotaForTaskForQueue::build),
+ MIN_START_FOR_TASK_FOR_QUEUE(MinStartForQueueQuota.KEY, MinStartForQueueQuota::build),
MAX_START_FOR_TASK_FOR_USER_FOR_QUEUE(
- "maxStartForTaskForUserForQueue", TaskQuotaForTaskForQueueForUser::build),
+ TaskQuotaForTaskForQueueForUser.KEY, TaskQuotaForTaskForQueueForUser::build),
MAX_START_PER_USER_FOR_TASK_FOR_QUEUE(
- "maxStartPerUserForTaskForQueue", TaskQuotaPerUserForTaskForQueue::build),
- SOFT_MAX_START_FOR_QUEUE_PER_USER("softMaxStartPerUserForQueue", SoftMaxPerUserForQueue::build);
+ TaskQuotaPerUserForTaskForQueue.KEY, TaskQuotaPerUserForTaskForQueue::build),
+ SOFT_MAX_START_FOR_QUEUE_PER_USER(SoftMaxPerUserForQueue.KEY, SoftMaxPerUserForQueue::build);
public final String key;
public final BiFunction<QuotaSection, String, Optional<TaskQuota>> processor;
diff --git a/src/main/java/com/googlesource/gerrit/plugins/quota/TaskQuotaLogFile.java b/src/main/java/com/googlesource/gerrit/plugins/quota/TaskQuotaLogFile.java
new file mode 100644
index 0000000..66c43ff
--- /dev/null
+++ b/src/main/java/com/googlesource/gerrit/plugins/quota/TaskQuotaLogFile.java
@@ -0,0 +1,30 @@
+// Copyright (C) 2025 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.googlesource.gerrit.plugins.quota;
+
+import com.google.gerrit.extensions.systemstatus.ServerInformation;
+import com.google.gerrit.server.util.PluginLogFile;
+import com.google.gerrit.server.util.SystemLog;
+import com.google.inject.Inject;
+import org.apache.log4j.PatternLayout;
+
+public class TaskQuotaLogFile extends PluginLogFile {
+ protected static String NAME = "quota_log";
+
+ @Inject
+ public TaskQuotaLogFile(SystemLog systemLog, ServerInformation serverInfo) {
+ super(systemLog, serverInfo, NAME, new PatternLayout("[%d] %m%n"));
+ }
+}
diff --git a/src/main/java/com/googlesource/gerrit/plugins/quota/TaskQuotaPerUserForTaskForQueue.java b/src/main/java/com/googlesource/gerrit/plugins/quota/TaskQuotaPerUserForTaskForQueue.java
index a7299a2..dc2ee64 100644
--- a/src/main/java/com/googlesource/gerrit/plugins/quota/TaskQuotaPerUserForTaskForQueue.java
+++ b/src/main/java/com/googlesource/gerrit/plugins/quota/TaskQuotaPerUserForTaskForQueue.java
@@ -22,10 +22,12 @@
public class TaskQuotaPerUserForTaskForQueue extends TaskQuotaForTaskForQueue {
public static final Logger log = LoggerFactory.getLogger(TaskQuotaPerUserForTaskForQueue.class);
+ public static final String KEY = "maxStartPerUserForTaskForQueue";
private final PerUserTaskQuota perUserTaskQuota;
- public TaskQuotaPerUserForTaskForQueue(String queue, String taskGroup, int maxStart) {
- super(queue, taskGroup, maxStart);
+ public TaskQuotaPerUserForTaskForQueue(
+ QuotaSection quotaSection, String queue, String taskGroup, int maxStart) {
+ super(quotaSection, queue, taskGroup, maxStart);
perUserTaskQuota = new PerUserTaskQuota(maxStart);
}
@@ -44,10 +46,17 @@
if (matcher.matches()) {
return Optional.of(
new TaskQuotaPerUserForTaskForQueue(
- matcher.group(3), matcher.group(2), Integer.parseInt(matcher.group(1))));
+ qs, matcher.group(3), matcher.group(2), Integer.parseInt(matcher.group(1))));
} else {
log.error("Invalid configuration entry [{}]", cfg);
return Optional.empty();
}
}
+
+ @Override
+ public String toString() {
+ return KEY
+ + ": task [%s], queue [%s], permits [%d], namespace [%s]"
+ .formatted(taskGroup, queueName, maxPermits, quotaSection.getNamespace());
+ }
}
diff --git a/src/main/java/com/googlesource/gerrit/plugins/quota/TaskQuotaWithPermits.java b/src/main/java/com/googlesource/gerrit/plugins/quota/TaskQuotaWithPermits.java
index ea414ca..ff7fe80 100644
--- a/src/main/java/com/googlesource/gerrit/plugins/quota/TaskQuotaWithPermits.java
+++ b/src/main/java/com/googlesource/gerrit/plugins/quota/TaskQuotaWithPermits.java
@@ -5,9 +5,11 @@
public abstract class TaskQuotaWithPermits implements TaskQuota {
protected final AtomicInteger permits;
+ protected final int maxPermits;
public TaskQuotaWithPermits(int maxPermits) {
this.permits = new AtomicInteger(maxPermits);
+ this.maxPermits = maxPermits;
}
public boolean isReadyToStart(WorkQueue.Task<?> task) {
diff --git a/src/main/java/com/googlesource/gerrit/plugins/quota/TaskQuotas.java b/src/main/java/com/googlesource/gerrit/plugins/quota/TaskQuotas.java
index 63a8bc1..5359bf5 100644
--- a/src/main/java/com/googlesource/gerrit/plugins/quota/TaskQuotas.java
+++ b/src/main/java/com/googlesource/gerrit/plugins/quota/TaskQuotas.java
@@ -28,12 +28,9 @@
import javax.inject.Inject;
import javax.inject.Singleton;
import org.eclipse.jgit.lib.Config;
-import org.slf4j.Logger;
-import org.slf4j.LoggerFactory;
@Singleton
public class TaskQuotas implements WorkQueue.TaskParker {
- private static final Logger log = LoggerFactory.getLogger(TaskQuotas.class);
private final QuotaFinder quotaFinder;
private final Map<Integer, List<TaskQuota>> quotasByTask = new ConcurrentHashMap<>();
private final Map<QuotaSection, List<TaskQuota>> quotasByNamespace = new HashMap<>();
@@ -83,8 +80,8 @@
@Override
public boolean isReadyToStart(WorkQueue.Task<?> task) {
- QueueManager.Queue queue = QueueManager.Queue.fromKey(task.getQueueName());
if (!QueueManager.acquire(task)) {
+ ParkedQuotaTransitionLogger.logTaskWithNoSatisfyingReservation(task);
return false;
}
@@ -105,7 +102,7 @@
for (TaskQuota quota : applicableQuotas) {
if (quota.isApplicable(task)) {
if (!quota.isReadyToStart(task)) {
- log.debug("Task [{}] will be parked due task quota rules", task);
+ ParkedQuotaTransitionLogger.logTaskWithEnforcedQuota(task, quota);
QueueManager.release(task);
acquiredQuotas.forEach(q -> q.onStop(task));
return false;
@@ -123,6 +120,7 @@
@Override
public void onNotReadyToStart(WorkQueue.Task<?> task) {
QueueManager.release(task);
+ ParkedQuotaTransitionLogger.clear(task);
Optional.ofNullable(quotasByTask.remove(task.getTaskId()))
.ifPresent(quotas -> quotas.forEach(q -> q.onStop(task)));
}
@@ -133,6 +131,7 @@
@Override
public void onStop(WorkQueue.Task<?> task) {
QueueManager.release(task);
+ ParkedQuotaTransitionLogger.clear(task);
Optional.ofNullable(quotasByTask.remove(task.getTaskId()))
.ifPresent(quotas -> quotas.forEach(q -> q.onStop(task)));
}
