Skip to content

Trace duration of classpath container updates #2374

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
vogella wants to merge 1 commit into
base: master
Choose a base branch
from
Open

Trace duration of classpath container updates #2374

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion ui/org.eclipse.pde.core/.options
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,5 +1,5 @@
org.eclipse.pde.core/debug=false
# trace for the classpath container and classpath computer
# trace for the classpath container and classpath computer, including the duration of classpath container updates
org.eclipse.pde.core/classpath=false
# prints the time taken to create the PDE plug-in models and OSGi state
org.eclipse.pde.core/model=false
Expand Down
16 changes: 16 additions & 0 deletions ui/org.eclipse.pde.core/src/org/eclipse/pde/internal/core/ClasspathContainerState.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -27,6 +27,7 @@
import java.util.Objects;
import java.util.Queue;
import java.util.concurrent.ConcurrentLinkedQueue;
import java.util.stream.Stream;

import org.eclipse.core.resources.IProject;
import org.eclipse.core.resources.IResource;
Expand Down Expand Up @@ -101,6 +102,7 @@ public boolean belongsTo(Object family) {

@Override
protected IStatus run(IProgressMonitor jobMonitor) {
long startNanos = PDECore.DEBUG_CLASSPATH ? System.nanoTime() : 0;

@HannesWell HannesWell Jun 18, 2026

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Since the output is in milliseconds, wouldn't it be suitable to use milliseconds from the beginning?

@vogella vogella Jun 18, 2026

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The traceRuntime helper keeps nanoTime() and only divides to ms at the end, so the durations stay monotonic (immune to wall-clock adjustments) while the output is in ms as before. Let me know if you'd still prefer currentTimeMillis().

@HannesWell HannesWell Jun 18, 2026

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

the durations stay monotonic (immune to wall-clock adjustments)

Have to admit that I haven’t considered that. I'd say that if one modifies a computer's clock it's acceptable to have wrong time recordings in tracing and System.currentTimeMillis() is sufficient (and a bit simpler).

But I'm also fine to keep it, no strict opposition from my side.

SubMonitor monitor = SubMonitor.convert(jobMonitor, PDECoreMessages.PluginModelManager_1, 100);
PluginModelManager.getInstance().initialize(monitor.split(1));
PluginModelManager modelManager = PluginModelManager.getInstance();
Expand All @@ -111,6 +113,7 @@ protected IStatus run(IProgressMonitor jobMonitor) {
int count = requests.size();
monitor.setWorkRemaining(count * 2);

long computeNanos = PDECore.DEBUG_CLASSPATH ? System.nanoTime() : 0;
String messageTemplate = PDECoreMessages.PluginModelManager_1 + " ({0}/{1}): {2}"; //$NON-NLS-1$
for (int i = 0; i < requests.size(); i++) {
UpdateRequest req = requests.get(i);
Expand Down Expand Up @@ -138,6 +141,7 @@ protected IStatus run(IProgressMonitor jobMonitor) {
}
monitor.worked(1);
}
traceRuntime("Computed classpath of %2$d project(s) in %1$d ms.", computeNanos, count); //$NON-NLS-1$
if (monitor.isCanceled()) {
return Status.CANCEL_STATUS;
}
Expand All @@ -163,11 +167,15 @@ protected IStatus run(IProgressMonitor jobMonitor) {
}
try {
monitor.setWorkRemaining(n);
long applyNanos = PDECore.DEBUG_CLASSPATH ? System.nanoTime() : 0;
setProjectContainers(javaProjects, container, monitor.split(n));
traceRuntime("Applied classpath container of %2$d project(s) in %1$d ms.", applyNanos, n); //$NON-NLS-1$
} catch (JavaModelException e) {
return e.getStatus();
}
}
traceRuntime("UpdateClasspathsJob finished in %d ms: %d request(s), %d updated, %d error(s).", startNanos, //$NON-NLS-1$
count, updateProjects.size(), errorsPerProject.size());
IStatus[] errors = errorsPerProject.values().toArray(IStatus[]::new);
if (errors.length == 0) {
return Status.OK_STATUS;
Expand Down Expand Up @@ -201,6 +209,14 @@ void add(IProject project, IClasspathContainer classpathContainer) {
schedule();
}

private void traceRuntime(String msg, long start, Object... args) {
if (PDECore.DEBUG_CLASSPATH) {
long elapsedMillis = (System.nanoTime() - start) / 1_000_000L;
Object[] allArgs = Stream.concat(Stream.of(elapsedMillis), Stream.of(args)).toArray();
PDECore.TRACE.trace(PDECore.KEY_DEBUG_CLASSPATH, String.format(msg, allArgs));
}
}

}

/**
Expand Down
3 changes: 2 additions & 1 deletion ui/org.eclipse.pde.core/src/org/eclipse/pde/internal/core/PDECore.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -95,8 +95,9 @@ public class PDECore extends Plugin implements DebugOptionsListener {

public static final String KEY_DEBUG_STATE = DEBUG + "/state"; //$NON-NLS-1$
public static final String KEY_DEBUG_VALIDATION = DEBUG + "/validation"; //$NON-NLS-1$
public static final String KEY_DEBUG_CLASSPATH = "/classpath"; //$NON-NLS-1$
private static final String DEBUG_FLAG = PLUGIN_ID + DEBUG;
private static final String CLASSPATH_DEBUG = PLUGIN_ID + "/classpath"; //$NON-NLS-1$
private static final String CLASSPATH_DEBUG = PLUGIN_ID + KEY_DEBUG_CLASSPATH;
private static final String MODEL_DEBUG = PLUGIN_ID + "/model"; //$NON-NLS-1$
private static final String TARGET_PROFILE_DEBUG = PLUGIN_ID + "/target/profile"; //$NON-NLS-1$
private static final String VALIDATION_DEBUG = PLUGIN_ID + KEY_DEBUG_VALIDATION;
Expand Down
Loading