codan - tracing options for printing checker stats

Change-Id: Ia0d1be6fc6be6092ae4b1dac84dff24fb722b1d5

codan/org.eclipse.cdt.codan.core/.options

@@ -0,0 +1,4 @@
+org.eclipse.cdt.codan.core/debug=false
+# Reports checkers performance on stdout when calling analysis on demand
+org.eclipse.cdt.codan.core/debug/performance=false
+

codan/org.eclipse.cdt.codan.core/src/org/eclipse/cdt/codan/core/CodanCorePlugin.java

@@ -10,13 +10,18 @@
  *******************************************************************************/
 package org.eclipse.cdt.codan.core;
 
+import org.eclipse.cdt.codan.internal.core.CheckersTimeStats;
 import org.eclipse.cdt.codan.internal.core.CodeAnalysisNature;
 import org.eclipse.core.runtime.IStatus;
 import org.eclipse.core.runtime.Plugin;
 import org.eclipse.core.runtime.Status;
 import org.eclipse.core.runtime.preferences.IEclipsePreferences;
 import org.eclipse.core.runtime.preferences.InstanceScope;
+import org.eclipse.osgi.service.debug.DebugOptions;
+import org.eclipse.osgi.service.debug.DebugTrace;
+import org.osgi.framework.Bundle;
 import org.osgi.framework.BundleContext;
+import org.osgi.util.tracker.ServiceTracker;
 
 /**
  * The activator class controls the plug-in life cycle
@@ -31,6 +36,8 @@ public class CodanCorePlugin extends Plugin {
 	public static final String NATURE_ID = CodeAnalysisNature.NATURE_ID;
 	// The shared instance
 	private static CodanCorePlugin plugin;
+	private static DebugTrace trace;
+	private static DebugOptions debugOptions;
 
 	/**
 	 * The constructor
@@ -55,6 +62,9 @@ public class CodanCorePlugin extends Plugin {
 	public void start(BundleContext context) throws Exception {
 		super.start(context);
 		plugin = this;
+		if (isDebuggingEnabled("/debug/performance")) { //$NON-NLS-1$
+			CheckersTimeStats.getInstance().setEnabled(true);
+		}
 	}
 
 	/*
@@ -120,4 +130,70 @@ public class CodanCorePlugin extends Plugin {
 	public static void log(String message) {
 		log(new Status(IStatus.ERROR, PLUGIN_ID, 1, message, null));
 	}
+
+	private final boolean isDebuggingEnabled(final String optionPath) {
+		if (optionPath == null)
+			return true;
+		if (debugOptions==null)
+			getTrace();
+		if (debugOptions==null)
+			return false;
+		boolean debugEnabled = false;
+		if (debugOptions.isDebugEnabled()) {
+			final String option = getDefault().getBundle().getSymbolicName() + optionPath;
+			debugEnabled = debugOptions.getBooleanOption(option, false);
+		}
+		return debugEnabled;
+	}
+
+	/**
+	 * Use a no-op trace when a real one isn't available. Simplifies life for
+	 * clients; no need to check for null.
+	 */
+	private static final DebugTrace NULL_TRACE = new DebugTrace() {
+		@Override
+		public void trace(String option, String message) {}
+		@Override
+		public void trace(String option, String message, Throwable error) {}
+		@Override
+		public void traceDumpStack(String option) {}
+		@Override
+		public void traceEntry(String option) {}
+		@Override
+		public void traceEntry(String option, Object methodArgument) {}
+		@Override
+		public void traceEntry(String option, Object[] methodArguments) {}
+		@Override
+		public void traceExit(String option) {}
+		@Override
+		public void traceExit(String option, Object result) {}
+	};
+
+
+	synchronized private static DebugTrace getTrace() {
+		if (trace == null) {
+			Plugin plugin = getDefault();
+			if (plugin != null) {
+				Bundle bundle = plugin.getBundle();
+				if (bundle != null) {
+					BundleContext context = bundle.getBundleContext();
+					if (context != null) {
+						ServiceTracker<DebugOptions, DebugOptions> tracker = new ServiceTracker<DebugOptions, DebugOptions>(context, DebugOptions.class.getName(), null);
+						try {
+							tracker.open();
+							debugOptions = tracker.getService();
+							if (debugOptions != null) {
+								trace = debugOptions.newDebugTrace(bundle.getSymbolicName());
+							}
+						}
+						finally {
+							tracker.close();
+						}
+					}
+				}
+			}
+
+		}
+		return trace != null ? trace : NULL_TRACE;
+	}
 }

codan/org.eclipse.cdt.codan.core/src/org/eclipse/cdt/codan/internal/core/CheckersTimeStats.java

@@ -21,6 +21,7 @@ public class CheckersTimeStats {
 	public static final String ALL = "ALL"; //$NON-NLS-1$
 	public static final String ELAPSED = "ELAPSED"; //$NON-NLS-1$
 	private static CheckersTimeStats instance = new CheckersTimeStats();
+	private boolean enableStats = false;
 
 	/**
 	 * @return global instance of stats
@@ -44,16 +45,15 @@ public class CheckersTimeStats {
 			current = 0;
 		}
 
-		/*
-		 * (non-Javadoc)
-		 *
-		 * @see java.lang.Object#toString()
-		 */
 		@Override
 		public String toString() {
-			if (count != 0)
+			return String.format("%4d %4d %4.2f", duration, count, count == 0 ? count : (duration / (float) count)); //$NON-NLS-1$
-				return duration + " " + count + " " + duration / count;  //$NON-NLS-1$//$NON-NLS-2$
+		}
-			return ""; //$NON-NLS-1$
+
+		public String toString(long total) {
+			float ave = count == 0 ? count : (duration / (float) count);
+			float per = total == 0 ? 100f : (duration * 100 / (float) total);
+			return String.format("%4d %4d %4.2f %4.2f%%", duration, count, ave, per); //$NON-NLS-1$
 		}
 	}
 	private Map<String, TimeRecord> records = new HashMap<String, TimeRecord>();
@@ -87,8 +87,14 @@ public class CheckersTimeStats {
 	 * @param counter
 	 */
 	public void checkerStart(String id, String counter) {
-		TimeRecord record = getTimeRecord(id + ":" + counter); //$NON-NLS-1$
+		if (enableStats) {
-		record.start();
+			TimeRecord record = getTimeRecord(getKey(id, counter));
+			record.start();
+		}
+	}
+
+	private String getKey(String id, String counter) {
+		return id + ":" + counter; //$NON-NLS-1$
 	}
 
 	/**
@@ -96,7 +102,9 @@ public class CheckersTimeStats {
 	 * @param counter
 	 */
 	public void checkerStop(String id, String counter) {
-		getTimeRecord(id + ":" + counter).stop(); //$NON-NLS-1$
+		if (enableStats) {
+			getTimeRecord(getKey(id, counter)).stop();
+		}
 	}
 
 	/**
@@ -107,11 +115,12 @@ public class CheckersTimeStats {
 	}
 
 	/**
-	 *
+	 * Print checker stats to stdout if tracing enabled
 	 */
 	public void traceStats() {
-		// TODO: add check for trace flags
+		if (enableStats) {
-		printStats();
+			printStats();
+		}
 	}
 
 	/**
@@ -119,11 +128,16 @@ public class CheckersTimeStats {
 	 */
 	public void printStats() {
 		System.out.println("---"); //$NON-NLS-1$
+		String totalId = getKey(ALL, ELAPSED);
+		TimeRecord all = records.get(totalId);
 		for (Iterator<String> iterator = records.keySet().iterator(); iterator.hasNext();) {
 			String id = iterator.next();
+			if (id.equals(totalId))
+				continue;
 			TimeRecord timeRecord = getTimeRecord(id);
-			System.out.println(timeRecord.toString() + " " + id); //$NON-NLS-1$
+			System.out.println(timeRecord.toString(all.duration) + " " + id); //$NON-NLS-1$
 		}
+		System.out.println(all.toString() + " " + totalId); //$NON-NLS-1$
 	}
 
 	/**
@@ -132,4 +146,18 @@ public class CheckersTimeStats {
 	public void reset() {
 		records.clear();
 	}
+
+	/**
+	 * @return true is stats collection is enabled
+	 */
+	public boolean isEnabled() {
+		return enableStats;
+	}
+
+	/**
+	 * @param set to true to enable stats collection and false to disable
+	 */
+	public void setEnabled(boolean enableStats) {
+		this.enableStats = enableStats;
+	}
 }

codan/org.eclipse.cdt.codan.ui/src/org/eclipse/cdt/codan/internal/ui/actions/RunCodeAnalysis.java

@@ -14,6 +14,7 @@ import java.util.Iterator;
 
 import org.eclipse.cdt.codan.core.CodanRuntime;
 import org.eclipse.cdt.codan.core.model.CheckerLaunchMode;
+import org.eclipse.cdt.codan.internal.core.CheckersTimeStats;
 import org.eclipse.cdt.codan.internal.ui.CodanUIMessages;
 import org.eclipse.core.resources.IResource;
 import org.eclipse.core.runtime.IAdaptable;
@@ -43,26 +44,31 @@ public class RunCodeAnalysis implements IObjectActionDelegate {
 			Job job = new Job(CodanUIMessages.Job_TitleRunningAnalysis) {
 				@Override
 				protected IStatus run(final IProgressMonitor monitor) {
-					int count = ss.size();
+					try {
-					monitor.beginTask(getName(), count * 100);
+						int count = ss.size();
-					if (monitor.isCanceled())
+						monitor.beginTask(getName(), count * 100);
-						return Status.CANCEL_STATUS;
-					for (Iterator iterator = ss.iterator(); iterator.hasNext();) {
-						Object o = iterator.next();
-						if (o instanceof IAdaptable) {
-							o = ((IAdaptable) o).getAdapter(IResource.class);
-						}
-						if (o instanceof IResource) {
-							IResource res = (IResource) o;
-							SubProgressMonitor subMon = new SubProgressMonitor(monitor, 100);
-							CodanRuntime.getInstance().getBuilder().processResource(res, subMon, CheckerLaunchMode.RUN_ON_DEMAND);
-							if (subMon.isCanceled())
-								return Status.CANCEL_STATUS;
-						}
 						if (monitor.isCanceled())
 							return Status.CANCEL_STATUS;
+						for (Iterator iterator = ss.iterator(); iterator.hasNext();) {
+							Object o = iterator.next();
+							if (o instanceof IAdaptable) {
+								o = ((IAdaptable) o).getAdapter(IResource.class);
+							}
+							if (o instanceof IResource) {
+								IResource res = (IResource) o;
+								SubProgressMonitor subMon = new SubProgressMonitor(monitor, 100);
+								CodanRuntime.getInstance().getBuilder().processResource(res, subMon, CheckerLaunchMode.RUN_ON_DEMAND);
+								if (subMon.isCanceled())
+									return Status.CANCEL_STATUS;
+							}
+							if (monitor.isCanceled())
+								return Status.CANCEL_STATUS;
+						}
+						return Status.OK_STATUS;
+					} finally {
+						CheckersTimeStats.getInstance().traceStats();
+						CheckersTimeStats.getInstance().reset();
 					}
-					return Status.OK_STATUS;
 				}
 			};
 			job.setUser(true);