Skip to content
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.

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

JBIDE-15012 dont update status bar so often, add tracing #161

Closed
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
21 changes: 21 additions & 0 deletions foundation/plugins/org.jboss.tools.foundation.core/.options
@@ -0,0 +1,21 @@
# Debugging options for the org.jboss.tools.foundation.core plugin

# Turn on general debugging
org.jboss.tools.foundation.core/debug=true

# Tracing options
org.jboss.tools.foundation.core/config=false
org.jboss.tools.foundation.core/info=false
org.jboss.tools.foundation.core/warning=false
org.jboss.tools.foundation.core/severe=false
org.jboss.tools.foundation.core/finest=false
org.jboss.tools.foundation.core/finer=false

# Tracking of resources
org.jboss.tools.foundation.core/resources=false

# Loading of extension points
org.jboss.tools.foundation.core/extension_point=false

# listeners
org.jboss.tools.foundation.core/listeners=false
@@ -0,0 +1,127 @@
/*******************************************************************************
* Copyright (c) 2003, 2011 IBM Corporation and others.
* All rights reserved. This program and the accompanying materials
* are made available under the terms of the Eclipse Public License v1.0
* which accompanies this distribution, and is available at
* http://www.eclipse.org/legal/epl-v10.html
*
* Contributors:
* IBM Corporation - Initial API and implementation
*******************************************************************************/
package org.jboss.tools.foundation.core;

import java.text.SimpleDateFormat;
import java.util.Date;
import java.util.HashSet;
import java.util.Set;

import org.eclipse.osgi.service.debug.DebugOptions;
import org.eclipse.osgi.service.debug.DebugOptionsListener;

/**
* Helper class to route trace output.
*/
public class Trace implements DebugOptionsListener {

private static final SimpleDateFormat sdf = new SimpleDateFormat("dd/MM/yy HH:mm.ss.SSS"); //$NON-NLS-1$

private static Set<String> logged = new HashSet<String>();

// tracing enablement flags
public static boolean CONFIG = false;
public static boolean INFO = false;
public static boolean WARNING = false;
public static boolean SEVERE = false;
public static boolean FINER = false;
public static boolean FINEST = false;
public static boolean RESOURCES = false;
public static boolean EXTENSION_POINT = false;
public static boolean LISTENERS = false;

// tracing levels. One most exist for each debug option
public final static String STRING_CONFIG = "/config"; //$NON-NLS-1$
public final static String STRING_INFO = "/info"; //$NON-NLS-1$
public final static String STRING_WARNING = "/warning"; //$NON-NLS-1$
public final static String STRING_SEVERE = "/severe"; //$NON-NLS-1$
public final static String STRING_FINER = "/finer"; //$NON-NLS-1$
public final static String STRING_FINEST = "/finest"; //$NON-NLS-1$
public final static String STRING_RESOURCES = "/resources"; //$NON-NLS-1$
public final static String STRING_EXTENSION_POINT = "/extension_point"; //$NON-NLS-1$
public final static String STRING_LISTENERS = "/listeners"; //$NON-NLS-1$

/**
* Trace constructor. This should never be explicitly called by clients and is used to register this class with the
* {@link DebugOptions} service.
*/
public Trace() {
super();
}

/*
* (non-Javadoc)
*
* @see
* org.eclipse.osgi.service.debug.DebugOptionsListener#optionsChanged(org.eclipse.osgi.service.debug.DebugOptions)
*/
public void optionsChanged(DebugOptions options) {
Trace.CONFIG = options.getBooleanOption(FoundationCorePlugin.PLUGIN_ID + Trace.STRING_CONFIG, false);
Trace.INFO = options.getBooleanOption(FoundationCorePlugin.PLUGIN_ID + Trace.STRING_INFO, false);
Trace.WARNING = options.getBooleanOption(FoundationCorePlugin.PLUGIN_ID + Trace.STRING_WARNING, false);
Trace.SEVERE = options.getBooleanOption(FoundationCorePlugin.PLUGIN_ID + Trace.STRING_SEVERE, false);
Trace.FINER = options.getBooleanOption(FoundationCorePlugin.PLUGIN_ID + Trace.STRING_FINER, false);
Trace.FINEST = options.getBooleanOption(FoundationCorePlugin.PLUGIN_ID + Trace.STRING_FINEST, false);
Trace.RESOURCES = options.getBooleanOption(FoundationCorePlugin.PLUGIN_ID + Trace.STRING_RESOURCES, false);
Trace.EXTENSION_POINT = options.getBooleanOption(FoundationCorePlugin.PLUGIN_ID + Trace.STRING_EXTENSION_POINT, false);
Trace.LISTENERS = options.getBooleanOption(FoundationCorePlugin.PLUGIN_ID + Trace.STRING_LISTENERS, false);
}

/**
* Trace the given message.
*
* @param level
* The tracing level.
* @param s
* The message to trace
*/
public static void trace(final String level, String s) {

Trace.trace(level, s, null);
}

/**
* Trace the given message and exception.
*
* @param level
* The tracing level.
* @param s
* The message to trace
* @param t
* A {@link Throwable} to trace
*/
public static void trace(final String level, String s, Throwable t) {
if (s == null) {
return;
}
if (Trace.STRING_SEVERE.equals(level)) {
if (!logged.contains(s)) {
FoundationCorePlugin.pluginLog().logError(s, t);
logged.add(s);
}
}
if (FoundationCorePlugin.getDefault().isDebugging()) {
final StringBuilder sb = new StringBuilder(FoundationCorePlugin.PLUGIN_ID);
sb.append(" "); //$NON-NLS-1$
sb.append(level);
sb.append(" "); //$NON-NLS-1$
sb.append(sdf.format(new Date()));
sb.append(" "); //$NON-NLS-1$
sb.append(s);
System.out.println(sb.toString());
if (t != null) {
t.printStackTrace();
}
}
}


}
Expand Up @@ -61,6 +61,7 @@
import org.eclipse.equinox.security.storage.StorageException;
import org.eclipse.osgi.util.NLS;
import org.jboss.tools.foundation.core.FoundationCorePlugin;
import org.jboss.tools.foundation.core.Trace;
import org.jboss.tools.foundation.core.ecf.Messages;
import org.jboss.tools.foundation.core.jobs.BarrierWaitJob;
import org.osgi.framework.Bundle;
Expand Down Expand Up @@ -136,6 +137,7 @@ public static synchronized InternalURLTransport getInstance() {
* @exception OperationCanceledException if the request was canceled.
*/
public long getLastModified(URL location, IProgressMonitor monitor) throws CoreException {
Trace.trace(Trace.STRING_FINER, "Checking last-modified timestamp for " + location.toExternalForm());
String locationString = location.toExternalForm();
try {
IConnectContext context = getConnectionContext(locationString, false);
Expand Down Expand Up @@ -190,6 +192,8 @@ private long doGetLastModified(String location, IConnectContext context, IProgre
* to download or not.
*/
public IStatus download(String name, String url, OutputStream destination, int timeout, IProgressMonitor monitor) {
Trace.trace(Trace.STRING_FINER, "Downloading url " + url + " to an outputstream");

IStatus status = null;
try {
IConnectContext context = getConnectionContext(url, false);
Expand Down Expand Up @@ -274,15 +278,26 @@ public IStatus performDownload(String name,String toDownload, OutputStream targe

private IStatus transfer(final String name,final IRetrieveFileTransferContainerAdapter retrievalContainer, final String toDownload,
final OutputStream target, IConnectContext context, int timeout, final IProgressMonitor monitor) throws ProtocolException {
Trace.trace(Trace.STRING_FINER, "Beginning transfer for remote file " + toDownload);

final IStatus[] result = new IStatus[1];
final IIncomingFileTransferReceiveStartEvent[] cancelable = new IIncomingFileTransferReceiveStartEvent[1];
cancelable[0] = null;

IFileTransferListener listener = new IFileTransferListener() {
private long transferStartTime;
protected int oldWorked;

// A temporary variable used to store work count
protected int tmpWorled;

// Ensure no updates to status until 250 ms due to possible mac bug with too many updates
private long throttleMilliseconds = 250;
private long lastProgressUpdate = System.currentTimeMillis();

public void handleTransferEvent(IFileTransferEvent event) {
if (event instanceof IIncomingFileTransferReceiveStartEvent) {
Trace.trace(Trace.STRING_FINER, "Transfer has begun for " + toDownload);
if( monitor.isCanceled()) {
synchronized(result) {
result[0] = FoundationCorePlugin.statusFactory().cancelStatus(Messages.ECFTransport_Operation_canceled);
Expand All @@ -302,6 +317,7 @@ public void handleTransferEvent(IFileTransferEvent event) {
final long totalWork = ((fileLength == -1) ? 100 : fileLength);
int work = (totalWork > Integer.MAX_VALUE) ? Integer.MAX_VALUE : (int) totalWork;
monitor.beginTask(NLS.bind(Messages.ECFExamplesTransport_Downloading, name), work);
lastProgressUpdate = System.currentTimeMillis();
oldWorked=0;
}
} catch (IOException e) {
Expand All @@ -328,30 +344,41 @@ public void handleTransferEvent(IFileTransferEvent event) {
}
return;
}
long fileLength = source.getFileLength();
final long totalWork = ((fileLength == -1) ? 100 : fileLength);
double factor = (totalWork > Integer.MAX_VALUE) ? (((double) Integer.MAX_VALUE) / ((double) totalWork)) : 1.0;
long received = source.getBytesReceived();
int worked = (int) Math.round(factor * received);
double downloadRateBytesPerSecond = (received / ((System.currentTimeMillis() + 1 - transferStartTime) / 1000.0));

String downloadRateString = AbstractRetrieveFileTransfer.toHumanReadableBytes(downloadRateBytesPerSecond);
String receivedString = AbstractRetrieveFileTransfer.toHumanReadableBytes(received);
String fileLengthString = AbstractRetrieveFileTransfer.toHumanReadableBytes(fileLength);
if( fileLength < 0 ) {
monitor.subTask(NLS.bind(
Messages.ECFExamplesTransport_ReceivedSize_At_RatePerSecond,
new String[]{receivedString, downloadRateString}));
} else {
monitor.subTask(NLS.bind(
Messages.ECFExamplesTransport_ReceivedSize_Of_FileSize_At_RatePerSecond,
new String[]{receivedString, fileLengthString, downloadRateString}));
long currentTime = System.currentTimeMillis();
if( lastProgressUpdate + throttleMilliseconds < currentTime ) {
long fileLength = source.getFileLength();
final long totalWork = ((fileLength == -1) ? 100 : fileLength);
double factor = (totalWork > Integer.MAX_VALUE) ? (((double) Integer.MAX_VALUE) / ((double) totalWork)) : 1.0;
long received = source.getBytesReceived();
int worked = (int) Math.round(factor * received);
double downloadRateBytesPerSecond = (received / ((System.currentTimeMillis() + 1 - transferStartTime) / 1000.0));

String downloadRateString = AbstractRetrieveFileTransfer.toHumanReadableBytes(downloadRateBytesPerSecond);
String receivedString = AbstractRetrieveFileTransfer.toHumanReadableBytes(received);
String fileLengthString = AbstractRetrieveFileTransfer.toHumanReadableBytes(fileLength);

String str = null;
if( fileLength < 0 ) {
str = NLS.bind(
Messages.ECFExamplesTransport_ReceivedSize_At_RatePerSecond,
new String[]{receivedString, downloadRateString});
} else {
str = NLS.bind(
Messages.ECFExamplesTransport_ReceivedSize_Of_FileSize_At_RatePerSecond,
new String[]{receivedString, fileLengthString, downloadRateString});
}

Trace.trace(Trace.STRING_FINEST, "Transfer " + toDownload + " status: " + str);
monitor.subTask(str);
lastProgressUpdate = currentTime;
monitor.worked(worked-oldWorked);
oldWorked=worked;
}
monitor.worked(worked-oldWorked);
oldWorked=worked;
}
}
if (event instanceof IIncomingFileTransferReceiveDoneEvent) {
Trace.trace(Trace.STRING_FINER, "Transfer " + toDownload + " is complete");
Exception exception = ((IIncomingFileTransferReceiveDoneEvent) event).getException();
IStatus status = convertToStatus(exception);
synchronized (result) {
Expand Down Expand Up @@ -547,13 +574,15 @@ private IStatus convertToStatus(Exception e) {
* Waits until the first entry in the given array is non-null.
*/
private void waitFor(String location, Object[] barrier) throws InterruptedException {
Trace.trace(Trace.STRING_FINER, "Waiting for remote file to download: " + location);
BarrierWaitJob.waitForSynchronous(Messages.ECFExamplesTransport_Loading, barrier, true);
}

private synchronized ServiceTracker getFileTransferServiceTracker() {
if (retrievalFactoryTracker == null) {
retrievalFactoryTracker = new ServiceTracker(FoundationCorePlugin.getDefault().getBundleContext(), IRetrieveFileTransferFactory.class.getName(), null);
retrievalFactoryTracker.open();
Trace.trace(Trace.STRING_FINER, "Ensuring all bundles for URLTransport are started");
requestStart(BUNDLE_ECF); //$NON-NLS-1$
requestStart(BUNDLE_ECF_FILETRANSFER); //$NON-NLS-1$
}
Expand Down Expand Up @@ -623,6 +652,7 @@ private boolean requestStart(String bundleId, Version version) {
* @return boolean whether the bundle is now active
*/
private boolean forceStart(String bundleId) {
Trace.trace(Trace.STRING_FINEST, "Forcing " + bundleId + " to start");
Bundle bundle = Platform.getBundle(bundleId); //$NON-NLS-1$
if (bundle != null && bundle.getState() != Bundle.ACTIVE) {
try {
Expand Down
Expand Up @@ -29,6 +29,7 @@
import org.eclipse.core.runtime.preferences.IEclipsePreferences;
import org.eclipse.core.runtime.preferences.InstanceScope;
import org.jboss.tools.foundation.core.FoundationCorePlugin;
import org.jboss.tools.foundation.core.Trace;
import org.jboss.tools.foundation.core.ecf.Messages;
import org.jboss.tools.foundation.core.ecf.URLTransportUtility;
import org.osgi.service.prefs.BackingStoreException;
Expand Down Expand Up @@ -72,6 +73,7 @@ public File getCachedFile(String url) {

public boolean isCacheOutdated(String url, IProgressMonitor monitor)
throws CoreException {
Trace.trace(Trace.STRING_FINER, "Checking if cache is outdated for " + url);
File f = getCachedFile(url);
if (f == null)
return true;
Expand Down Expand Up @@ -109,6 +111,8 @@ public boolean isCacheOutdated(String url, IProgressMonitor monitor)

public File downloadAndCache(String url, String displayName, int lifespan,
URLTransportUtility util, IProgressMonitor monitor) throws CoreException {
Trace.trace(Trace.STRING_FINER, "Downloading and caching " + url + " with lifespan=" + lifespan);

File target = getRemoteFileCacheLocation(url);
try {
OutputStream os = new FileOutputStream(target);
Expand All @@ -134,18 +138,19 @@ private void addToCache(String url, File target) {
private void loadPreferences() {
IEclipsePreferences prefs = InstanceScope.INSTANCE.getNode(FoundationCorePlugin.PLUGIN_ID);
String val = prefs.get(CACHE_MAP_KEY, "");
if( isEmpty(val))
return;
String[] byLine = val.split("\n");
for( int i = 0; i < byLine.length; i++ ) {
if( isEmpty(byLine[i]))
continue;
String[] kv = byLine[i].split("=");
if( kv.length == 2 && !isEmpty(kv[0]) && !isEmpty(kv[1])) {
if( new File(kv[1]).exists() )
cache.put(kv[0],kv[1]);
if( !isEmpty(val)) {
String[] byLine = val.split("\n");
for( int i = 0; i < byLine.length; i++ ) {
if( isEmpty(byLine[i]))
continue;
String[] kv = byLine[i].split("=");
if( kv.length == 2 && !isEmpty(kv[0]) && !isEmpty(kv[1])) {
if( new File(kv[1]).exists() )
cache.put(kv[0],kv[1]);
}
}
}
Trace.trace(Trace.STRING_FINER, "Loaded " + cache.size() + " cache file locations from preferences");
}

private boolean isEmpty(String s) {
Expand All @@ -157,6 +162,8 @@ private void savePreferences() {
// saves plugin preferences at the workspace level
IEclipsePreferences prefs = InstanceScope.INSTANCE.getNode(FoundationCorePlugin.PLUGIN_ID);

Trace.trace(Trace.STRING_FINER, "Saving " + cache.size() + " cache file locations to preferences");

StringBuffer sb = new StringBuffer();
Iterator<String> it = cache.keySet().iterator();
while(it.hasNext()) {
Expand Down