motiejus
/
jgit
1
Fork 0
Code Releases Activity

BatchingProgressMonitor: expose time spent per task 

Display elapsed time per task if enabled via
ProgressMonitor#showDuration or if system property or environment
variable GIT_TRACE_PERFORMANCE is set to "true". If both the system
property and the environment variable are set the system property takes
precedence.

E.g. using jgit CLI:

$ GIT_TRACE_PERFORMANCE=true jgit clone https://foo.bar/foobar
Cloning into 'foobar'...
remote: Counting objects: 1 [0.002s]
remote: Finding sources: 100% (15531/15531) [0.006s]
Receiving objects:      100% (169737/169737) [13.045s]
Resolving deltas:       100% (67579/67579) [1.842s]

Change-Id: I4d624e7858b286aeddbe7d4e557589986d73659e
This commit is contained in:
Matthias Sohn 2023-01-19 01:46:50 +01:00
parent ca2c57b2ec
commit 2d0b908048
12 changed files with 274 additions and 33 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

5
org.eclipse.jgit.junit/src/org/eclipse/jgit/junit/StrictWorkMonitor.java
View File

@ -50,4 +50,9 @@ public void endTask() {
public boolean isCancelled() {
return false;
}
@Override
public void showDuration(boolean enabled) {
// not implemented
}
}

5
org.eclipse.jgit.test/tst/org/eclipse/jgit/internal/storage/io/CancellableDigestOutputStreamTest.java
View File

@ -54,6 +54,11 @@ public void endTask() {
public boolean isCancelled() {
return cancelled;
}
@Override
public void showDuration(boolean enabled) {
// not implemented
}
}
@Test

5
org.eclipse.jgit.test/tst/org/eclipse/jgit/lib/ThreadSafeProgressMonitorTest.java
View File

@ -167,5 +167,10 @@ public void endTask() {
public boolean isCancelled() {
return false;
}
@Override
public void showDuration(boolean enabled) {
// not implemented
}
}
}

84
org.eclipse.jgit/.settings/.api_filters
View File

@ -1,5 +1,55 @@
<?xml version="1.0" encoding="UTF-8" standalone="no"?>
<component id="org.eclipse.jgit" version="2">
<resource path="src/org/eclipse/jgit/lib/BatchingProgressMonitor.java" type="org.eclipse.jgit.lib.BatchingProgressMonitor">
<filter id="336695337">
<message_arguments>
<message_argument value="org.eclipse.jgit.lib.BatchingProgressMonitor"/>
<message_argument value="onEndTask(String, int, Duration)"/>
</message_arguments>
</filter>
<filter id="336695337">
<message_arguments>
<message_argument value="org.eclipse.jgit.lib.BatchingProgressMonitor"/>
<message_argument value="onEndTask(String, int, int, int, Duration)"/>
</message_arguments>
</filter>
<filter id="336695337">
<message_arguments>
<message_argument value="org.eclipse.jgit.lib.BatchingProgressMonitor"/>
<message_argument value="onUpdate(String, int, Duration)"/>
</message_arguments>
</filter>
<filter id="336695337">
<message_arguments>
<message_argument value="org.eclipse.jgit.lib.BatchingProgressMonitor"/>
<message_argument value="onUpdate(String, int, int, int, Duration)"/>
</message_arguments>
</filter>
<filter id="338792546">
<message_arguments>
<message_argument value="org.eclipse.jgit.lib.BatchingProgressMonitor"/>
<message_argument value="onEndTask(String, int)"/>
</message_arguments>
</filter>
<filter id="338792546">
<message_arguments>
<message_argument value="org.eclipse.jgit.lib.BatchingProgressMonitor"/>
<message_argument value="onEndTask(String, int, int, int)"/>
</message_arguments>
</filter>
<filter id="338792546">
<message_arguments>
<message_argument value="org.eclipse.jgit.lib.BatchingProgressMonitor"/>
<message_argument value="onUpdate(String, int)"/>
</message_arguments>
</filter>
<filter id="338792546">
<message_arguments>
<message_argument value="org.eclipse.jgit.lib.BatchingProgressMonitor"/>
<message_argument value="onUpdate(String, int, int, int)"/>
</message_arguments>
</filter>
</resource>
<resource path="src/org/eclipse/jgit/lib/ConfigConstants.java" type="org.eclipse.jgit.lib.ConfigConstants">
<filter id="1142947843">
<message_arguments>
@ -42,6 +92,14 @@
</message_arguments>
</filter>
</resource>
<resource path="src/org/eclipse/jgit/lib/ProgressMonitor.java" type="org.eclipse.jgit.lib.ProgressMonitor">
<filter id="403804204">
<message_arguments>
<message_argument value="org.eclipse.jgit.lib.ProgressMonitor"/>
<message_argument value="showDuration(boolean)"/>
</message_arguments>
</filter>
</resource>
<resource path="src/org/eclipse/jgit/lib/RefDatabase.java" type="org.eclipse.jgit.lib.RefDatabase">
<filter id="336658481">
<message_arguments>
@ -58,6 +116,32 @@
</message_arguments>
</filter>
</resource>
<resource path="src/org/eclipse/jgit/lib/TextProgressMonitor.java" type="org.eclipse.jgit.lib.TextProgressMonitor">
<filter id="338792546">
<message_arguments>
<message_argument value="org.eclipse.jgit.lib.TextProgressMonitor"/>
<message_argument value="onEndTask(String, int)"/>
</message_arguments>
</filter>
<filter id="338792546">
<message_arguments>
<message_argument value="org.eclipse.jgit.lib.TextProgressMonitor"/>
<message_argument value="onEndTask(String, int, int, int)"/>
</message_arguments>
</filter>
<filter id="338792546">
<message_arguments>
<message_argument value="org.eclipse.jgit.lib.TextProgressMonitor"/>
<message_argument value="onUpdate(String, int)"/>
</message_arguments>
</filter>
<filter id="338792546">
<message_arguments>
<message_argument value="org.eclipse.jgit.lib.TextProgressMonitor"/>
<message_argument value="onUpdate(String, int, int, int)"/>
</message_arguments>
</filter>
</resource>
<resource path="src/org/eclipse/jgit/storage/pack/PackConfig.java" type="org.eclipse.jgit.storage.pack.PackConfig">
<filter id="336658481">
<message_arguments>

100
org.eclipse.jgit/src/org/eclipse/jgit/lib/BatchingProgressMonitor.java
View File

@ -10,21 +10,29 @@
package org.eclipse.jgit.lib;
import java.time.Duration;
import java.time.Instant;
import java.util.concurrent.Future;
import java.util.concurrent.TimeUnit;
import org.eclipse.jgit.lib.internal.WorkQueue;
import org.eclipse.jgit.util.SystemReader;
/**
* ProgressMonitor that batches update events.
*/
public abstract class BatchingProgressMonitor implements ProgressMonitor {
private static boolean performanceTrace = SystemReader.getInstance()
.isPerformanceTraceEnabled();
private long delayStartTime;
private TimeUnit delayStartUnit = TimeUnit.MILLISECONDS;
private Task task;
private Boolean showDuration;
/**
* Set an optional delay before the first output.
*
@ -76,6 +84,11 @@ public boolean isCancelled() {
return false;
}
@Override
public void showDuration(boolean enabled) {
showDuration = Boolean.valueOf(enabled);
}
/**
* Update the progress monitor if the total work isn't known,
*
@ -83,8 +96,12 @@ public boolean isCancelled() {
* name of the task.
* @param workCurr
* number of units already completed.
* @param duration
* how long this task runs
* @since 6.5
*/
protected abstract void onUpdate(String taskName, int workCurr);
protected abstract void onUpdate(String taskName, int workCurr,
Duration duration);
/**
* Finish the progress monitor when the total wasn't known in advance.
@ -93,8 +110,12 @@ public boolean isCancelled() {
* name of the task.
* @param workCurr
* total number of units processed.
* @param duration
* how long this task runs
* @since 6.5
*/
protected abstract void onEndTask(String taskName, int workCurr);
protected abstract void onEndTask(String taskName, int workCurr,
Duration duration);
/**
* Update the progress monitor when the total is known in advance.
@ -107,9 +128,12 @@ public boolean isCancelled() {
* estimated number of units to process.
* @param percentDone
* {@code workCurr * 100 / workTotal}.
* @param duration
* how long this task runs
* @since 6.5
*/
protected abstract void onUpdate(String taskName, int workCurr,
int workTotal, int percentDone);
int workTotal, int percentDone, Duration duration);
/**
* Finish the progress monitor when the total is known in advance.
@ -122,9 +146,58 @@ protected abstract void onUpdate(String taskName, int workCurr,
* estimated number of units to process.
* @param percentDone
* {@code workCurr * 100 / workTotal}.
* @param duration
* duration of the task
* @since 6.5
*/
protected abstract void onEndTask(String taskName, int workCurr,
int workTotal, int percentDone);
int workTotal, int percentDone, Duration duration);
private boolean showDuration() {
return showDuration != null ? showDuration.booleanValue()
: performanceTrace;
}
/**
* Append formatted duration if system property or environment variable
* GIT_TRACE_PERFORMANCE is set to "true". If both are defined the system
* property takes precedence.
*
* @param s
* StringBuilder to append the formatted duration to
* @param duration
* duration to format
* @since 6.5
*/
@SuppressWarnings({ "boxing", "nls" })
protected void appendDuration(StringBuilder s, Duration duration) {
if (!showDuration()) {
return;
}
long hours = duration.toHours();
int minutes = duration.toMinutesPart();
int seconds = duration.toSecondsPart();
s.append(" [");
if (hours > 0) {
s.append(hours).append(':');
s.append(String.format("%02d", minutes)).append(':');
s.append(String.format("%02d", seconds));
} else if (minutes > 0) {
s.append(minutes).append(':');
s.append(String.format("%02d", seconds));
} else {
s.append(seconds);
}
s.append('.').append(String.format("%03d", duration.toMillisPart()));
if (hours > 0) {
s.append('h');
} else if (minutes > 0) {
s.append('m');
} else {
s.append('s');
}
s.append(']');
}
private static class Task implements Runnable {
/** Title of the current task. */
@ -148,10 +221,13 @@ private static class Task implements Runnable {
/** Percentage of {@link #totalWork} that is done. */
private int lastPercent;
private final Instant startTime;
Task(String taskName, int totalWork) {
this.taskName = taskName;
this.totalWork = totalWork;
this.display = true;
this.startTime = Instant.now();
}
void delay(long time, TimeUnit unit) {
@ -170,7 +246,7 @@ void update(BatchingProgressMonitor pm, int completed) {
if (totalWork == UNKNOWN) {
// Only display once per second, as the alarm fires.
if (display) {
pm.onUpdate(taskName, lastWork);
pm.onUpdate(taskName, lastWork, elapsedTime());
output = true;
restartTimer();
}
@ -178,12 +254,14 @@ void update(BatchingProgressMonitor pm, int completed) {
// Display once per second or when 1% is done.
int currPercent = Math.round(lastWork * 100F / totalWork);
if (display) {
pm.onUpdate(taskName, lastWork, totalWork, currPercent);
pm.onUpdate(taskName, lastWork, totalWork, currPercent,
elapsedTime());
output = true;
restartTimer();
lastPercent = currPercent;
} else if (currPercent != lastPercent) {
pm.onUpdate(taskName, lastWork, totalWork, currPercent);
pm.onUpdate(taskName, lastWork, totalWork, currPercent,
elapsedTime());
output = true;
lastPercent = currPercent;
}
@ -199,14 +277,18 @@ private void restartTimer() {
void end(BatchingProgressMonitor pm) {
if (output) {
if (totalWork == UNKNOWN) {
pm.onEndTask(taskName, lastWork);
pm.onEndTask(taskName, lastWork, elapsedTime());
} else {
int currPercent = Math.round(lastWork * 100F / totalWork);
pm.onEndTask(taskName, lastWork, totalWork, currPercent);
pm.onEndTask(taskName, lastWork, totalWork, currPercent, elapsedTime());
}
}
if (timerFuture != null)
timerFuture.cancel(false /* no interrupt */);
}
private Duration elapsedTime() {
return Duration.between(startTime, Instant.now());
}
}
}

4
org.eclipse.jgit/src/org/eclipse/jgit/lib/EmptyProgressMonitor.java
View File

@ -48,4 +48,8 @@ public boolean isCancelled() {
return false;
}
@Override
public void showDuration(boolean enabled) {
// not implemented
}
}

5
org.eclipse.jgit/src/org/eclipse/jgit/lib/NullProgressMonitor.java
View File

@ -52,4 +52,9 @@ public boolean isCancelled() {
public void endTask() {
// Do not report.
}
@Override
public void showDuration(boolean enabled) {
// don't show
}
}

9
org.eclipse.jgit/src/org/eclipse/jgit/lib/ProgressMonitor.java
View File

@ -65,4 +65,13 @@ public interface ProgressMonitor {
* @return true if the user asked the process to stop working.
*/
boolean isCancelled();
/**
* Set whether the monitor should show elapsed time per task
*
* @param enabled
* whether to show elapsed time per task
* @since 6.5
*/
void showDuration(boolean enabled);
}

30
org.eclipse.jgit/src/org/eclipse/jgit/lib/TextProgressMonitor.java
View File

@ -17,6 +17,7 @@
import java.io.OutputStreamWriter;
import java.io.PrintWriter;
import java.io.Writer;
import java.time.Duration;
/**
* A simple progress reporter printing on a stream.
@ -46,49 +47,53 @@ public TextProgressMonitor(Writer out) {
/** {@inheritDoc} */
@Override
protected void onUpdate(String taskName, int workCurr) {
protected void onUpdate(String taskName, int workCurr, Duration duration) {
StringBuilder s = new StringBuilder();
format(s, taskName, workCurr);
format(s, taskName, workCurr, duration);
send(s);
}
/** {@inheritDoc} */
@Override
protected void onEndTask(String taskName, int workCurr) {
protected void onEndTask(String taskName, int workCurr, Duration duration) {
StringBuilder s = new StringBuilder();
format(s, taskName, workCurr);
format(s, taskName, workCurr, duration);
s.append("\n"); //$NON-NLS-1$
send(s);
}
private void format(StringBuilder s, String taskName, int workCurr) {
private void format(StringBuilder s, String taskName, int workCurr,
Duration duration) {
s.append("\r"); //$NON-NLS-1$
s.append(taskName);
s.append(": "); //$NON-NLS-1$
while (s.length() < 25)
s.append(' ');
s.append(workCurr);
appendDuration(s, duration);
}
/** {@inheritDoc} */
@Override
protected void onUpdate(String taskName, int cmp, int totalWork, int pcnt) {
protected void onUpdate(String taskName, int cmp, int totalWork, int pcnt,
Duration duration) {
StringBuilder s = new StringBuilder();
format(s, taskName, cmp, totalWork, pcnt);
format(s, taskName, cmp, totalWork, pcnt, duration);
send(s);
}
/** {@inheritDoc} */
@Override
protected void onEndTask(String taskName, int cmp, int totalWork, int pcnt) {
protected void onEndTask(String taskName, int cmp, int totalWork, int pcnt,
Duration duration) {
StringBuilder s = new StringBuilder();
format(s, taskName, cmp, totalWork, pcnt);
format(s, taskName, cmp, totalWork, pcnt, duration);
s.append("\n"); //$NON-NLS-1$
send(s);
}
private void format(StringBuilder s, String taskName, int cmp,
int totalWork, int pcnt) {
int totalWork, int pcnt, Duration duration) {
s.append("\r"); //$NON-NLS-1$
s.append(taskName);
s.append(": "); //$NON-NLS-1$
@ -106,9 +111,10 @@ private void format(StringBuilder s, String taskName, int cmp,
s.append(pcnt);
s.append("% ("); //$NON-NLS-1$
s.append(curStr);
s.append("/"); //$NON-NLS-1$
s.append('/');
s.append(endStr);
s.append(")"); //$NON-NLS-1$
s.append(')');
appendDuration(s, duration);
}
private void send(StringBuilder s) {

5
org.eclipse.jgit/src/org/eclipse/jgit/lib/ThreadSafeProgressMonitor.java
View File

@ -158,6 +158,11 @@ public void endTask() {
pm.endTask();
}
@Override
public void showDuration(boolean enabled) {
pm.showDuration(enabled);
}
private boolean isMainThread() {
return Thread.currentThread() == mainThread;
}

30
org.eclipse.jgit/src/org/eclipse/jgit/transport/SideBandProgressMonitor.java
View File

@ -12,6 +12,7 @@
import java.io.IOException;
import java.io.OutputStream;
import java.time.Duration;
import org.eclipse.jgit.lib.BatchingProgressMonitor;
import org.eclipse.jgit.lib.Constants;
@ -29,48 +30,52 @@ class SideBandProgressMonitor extends BatchingProgressMonitor {
/** {@inheritDoc} */
@Override
protected void onUpdate(String taskName, int workCurr) {
protected void onUpdate(String taskName, int workCurr, Duration duration) {
StringBuilder s = new StringBuilder();
format(s, taskName, workCurr);
format(s, taskName, workCurr, duration);
s.append(" \r"); //$NON-NLS-1$
send(s);
}
/** {@inheritDoc} */
@Override
protected void onEndTask(String taskName, int workCurr) {
protected void onEndTask(String taskName, int workCurr, Duration duration) {
StringBuilder s = new StringBuilder();
format(s, taskName, workCurr);
format(s, taskName, workCurr, duration);
s.append(", done\n"); //$NON-NLS-1$
send(s);
}
private void format(StringBuilder s, String taskName, int workCurr) {
private void format(StringBuilder s, String taskName, int workCurr,
Duration duration) {
s.append(taskName);
s.append(": "); //$NON-NLS-1$
s.append(workCurr);
appendDuration(s, duration);
}
/** {@inheritDoc} */
@Override
protected void onUpdate(String taskName, int cmp, int totalWork, int pcnt) {
protected void onUpdate(String taskName, int cmp, int totalWork, int pcnt,
Duration duration) {
StringBuilder s = new StringBuilder();
format(s, taskName, cmp, totalWork, pcnt);
format(s, taskName, cmp, totalWork, pcnt, duration);
s.append(" \r"); //$NON-NLS-1$
send(s);
}
/** {@inheritDoc} */
@Override
protected void onEndTask(String taskName, int cmp, int totalWork, int pcnt) {
protected void onEndTask(String taskName, int cmp, int totalWork, int pcnt,
Duration duration) {
StringBuilder s = new StringBuilder();
format(s, taskName, cmp, totalWork, pcnt);
format(s, taskName, cmp, totalWork, pcnt, duration);
s.append("\n"); //$NON-NLS-1$
send(s);
}
private void format(StringBuilder s, String taskName, int cmp,
int totalWork, int pcnt) {
int totalWork, int pcnt, Duration duration) {
s.append(taskName);
s.append(": "); //$NON-NLS-1$
if (pcnt < 100)
@ -80,9 +85,10 @@ private void format(StringBuilder s, String taskName, int cmp,
s.append(pcnt);
s.append("% ("); //$NON-NLS-1$
s.append(cmp);
s.append("/"); //$NON-NLS-1$
s.append('/');
s.append(totalWork);
s.append(")"); //$NON-NLS-1$
s.append(')');
appendDuration(s, duration);
}
private void send(StringBuilder s) {

25
org.eclipse.jgit/src/org/eclipse/jgit/util/SystemReader.java
View File

@ -65,6 +65,21 @@ public abstract class SystemReader {
private static volatile Boolean isLinux;
private static final String GIT_TRACE_PERFORMANCE = "GIT_TRACE_PERFORMANCE"; //$NON-NLS-1$
private static final boolean performanceTrace = initPerformanceTrace();
private static boolean initPerformanceTrace() {
String val = System.getenv(GIT_TRACE_PERFORMANCE);
if (val == null) {
val = System.getenv(GIT_TRACE_PERFORMANCE);
}
if (val != null) {
return Boolean.valueOf(val).booleanValue();
}
return false;
}
static {
SystemReader r = new Default();
r.init();
@ -560,6 +575,16 @@ public boolean isLinux() {
return isLinux.booleanValue();
}
/**
* Whether performance trace is enabled
*
* @return whether performance trace is enabled
* @since 6.5
*/
public boolean isPerformanceTraceEnabled() {
return performanceTrace;
}
private String getOsName() {
return AccessController.doPrivileged(
(PrivilegedAction<String>) () -> getProperty("os.name") //$NON-NLS-1$