Bug 318495 - add AST evaluation tracing
diff --git a/org.eclipse.jdt.debug/.options b/org.eclipse.jdt.debug/.options
index 66f229c..3ef5cf6 100644
--- a/org.eclipse.jdt.debug/.options
+++ b/org.eclipse.jdt.debug/.options
@@ -1,3 +1,6 @@
org.eclipse.jdt.debug/debug=false
org.eclipse.jdt.debug/debug/jdiEvents=false
org.eclipse.jdt.debug/debug/jdiRequestTimes=false
+org.eclipse.jdt.debug/debug/astEvaluations=false
+org.eclipse.jdt.debug/debug/astEvaluations/callingThreads=false
+
diff --git a/org.eclipse.jdt.debug/eval/org/eclipse/jdt/internal/debug/eval/ast/engine/ASTEvaluationEngine.java b/org.eclipse.jdt.debug/eval/org/eclipse/jdt/internal/debug/eval/ast/engine/ASTEvaluationEngine.java
index b9c8650..8e722a4 100644
--- a/org.eclipse.jdt.debug/eval/org/eclipse/jdt/internal/debug/eval/ast/engine/ASTEvaluationEngine.java
+++ b/org.eclipse.jdt.debug/eval/org/eclipse/jdt/internal/debug/eval/ast/engine/ASTEvaluationEngine.java
@@ -11,6 +11,7 @@
package org.eclipse.jdt.internal.debug.eval.ast.engine;
+import java.util.Date;
import java.util.HashSet;
import java.util.Map;
import java.util.Set;
@@ -27,6 +28,7 @@
import org.eclipse.debug.core.DebugPlugin;
import org.eclipse.debug.core.IDebugEventFilter;
import org.eclipse.debug.core.model.ITerminate;
+import org.eclipse.debug.core.model.IThread;
import org.eclipse.jdt.core.IJavaProject;
import org.eclipse.jdt.core.Signature;
import org.eclipse.jdt.core.compiler.IProblem;
@@ -50,6 +52,7 @@
import org.eclipse.jdt.debug.eval.ICompiledExpression;
import org.eclipse.jdt.debug.eval.IEvaluationListener;
import org.eclipse.jdt.debug.eval.IEvaluationResult;
+import org.eclipse.jdt.internal.debug.core.JDIDebugOptions;
import org.eclipse.jdt.internal.debug.core.JDIDebugPlugin;
import org.eclipse.jdt.internal.debug.core.model.JDIDebugTarget;
import org.eclipse.jdt.internal.debug.core.model.JDIThread;
@@ -111,6 +114,7 @@
* @see org.eclipse.jdt.debug.eval.IEvaluationEngine#evaluate(java.lang.String, org.eclipse.jdt.debug.core.IJavaStackFrame, org.eclipse.jdt.debug.eval.IEvaluationListener, int, boolean)
*/
public void evaluate(String snippet, IJavaStackFrame frame, IEvaluationListener listener, int evaluationDetail, boolean hitBreakpoints) throws DebugException {
+ traceCaller(snippet, frame.getThread());
checkInterface(frame);
ICompiledExpression expression= getCompiledExpression(snippet, frame);
evaluateExpression(expression, frame, listener, evaluationDetail, hitBreakpoints);
@@ -120,9 +124,37 @@
* @see org.eclipse.jdt.debug.eval.IEvaluationEngine#evaluate(java.lang.String, org.eclipse.jdt.debug.core.IJavaObject, org.eclipse.jdt.debug.core.IJavaThread, org.eclipse.jdt.debug.eval.IEvaluationListener, int, boolean)
*/
public void evaluate(String snippet, IJavaObject thisContext, IJavaThread thread, IEvaluationListener listener, int evaluationDetail, boolean hitBreakpoints) throws DebugException {
+ traceCaller(snippet, thread);
ICompiledExpression expression= getCompiledExpression(snippet, thisContext);
evaluateExpression(expression, thisContext, thread, listener, evaluationDetail, hitBreakpoints);
}
+
+ /**
+ * Writes a stack dump to trace the calling thread.
+ *
+ * @param snippet expression to evaluate
+ * @param thread thread to evaluate in
+ */
+ private void traceCaller(String snippet, IThread thread) {
+ if (JDIDebugOptions.DEBUG_AST_EVAL_THREAD_TRACE) {
+ StringBuffer buf = new StringBuffer();
+ buf.append(JDIDebugOptions.FORMAT.format(new Date()));
+ buf.append(" : Evaluation Request Trace - Expression: "); //$NON-NLS-1$
+ buf.append(snippet);
+ buf.append("\n\tThread: "); //$NON-NLS-1$
+ try {
+ String name = thread.getName();
+ buf.append('[');
+ buf.append(name);
+ buf.append("] "); //$NON-NLS-1$
+ } catch (DebugException e) {
+ buf.append(thread.toString());
+ }
+ System.out.println(buf.toString());
+ System.out.flush();
+ Thread.dumpStack();
+ }
+ }
/**
* Checks if the stack frame is declared in an interface an aborts
@@ -143,6 +175,7 @@
* @see org.eclipse.jdt.debug.eval.IAstEvaluationEngine#evaluateExpression(org.eclipse.jdt.debug.eval.ICompiledExpression, org.eclipse.jdt.debug.core.IJavaStackFrame, org.eclipse.jdt.debug.eval.IEvaluationListener, int, boolean)
*/
public void evaluateExpression(ICompiledExpression expression, IJavaStackFrame frame, IEvaluationListener listener, int evaluationDetail, boolean hitBreakpoints) throws DebugException {
+ traceCaller(expression.getSnippet(), frame.getThread());
RuntimeContext context = new RuntimeContext(getJavaProject(), frame);
doEvaluation(expression, context, (IJavaThread)frame.getThread(), listener, evaluationDetail, hitBreakpoints);
}
@@ -151,6 +184,7 @@
* @see org.eclipse.jdt.debug.eval.IAstEvaluationEngine#evaluateExpression(org.eclipse.jdt.debug.eval.ICompiledExpression, org.eclipse.jdt.debug.core.IJavaObject, org.eclipse.jdt.debug.core.IJavaThread, org.eclipse.jdt.debug.eval.IEvaluationListener, int, boolean)
*/
public void evaluateExpression(ICompiledExpression expression, IJavaObject thisContext, IJavaThread thread, IEvaluationListener listener, int evaluationDetail, boolean hitBreakpoints) throws DebugException {
+ traceCaller(expression.getSnippet(), thread);
IRuntimeContext context = null;
if (thisContext instanceof IJavaArray) {
context = new ArrayRuntimeContext((IJavaArray) thisContext, thread, getJavaProject());
@@ -460,6 +494,33 @@
}
public void run() {
+ if (JDIDebugOptions.DEBUG_AST_EVAL) {
+ StringBuffer buf = new StringBuffer();
+ buf.append(JDIDebugOptions.FORMAT.format(new Date()));
+ buf.append(" : AST Evaluation"); //$NON-NLS-1$
+ buf.append("\n\tExpression: "); //$NON-NLS-1$
+ buf.append(fExpression.getSnippet());
+ buf.append("\n\tThread: "); //$NON-NLS-1$
+ try {
+ String name = fThread.getName();
+ buf.append('[');
+ buf.append(name);
+ buf.append("] "); //$NON-NLS-1$
+ } catch (DebugException e) {
+ }
+ buf.append(fThread.toString());
+ buf.append("\n\tDetail: "); //$NON-NLS-1$
+ if (fEvaluationDetail == DebugEvent.EVALUATION) {
+ buf.append("EVALUATION"); //$NON-NLS-1$
+ } else if (fEvaluationDetail == DebugEvent.EVALUATION_IMPLICIT) {
+ buf.append("EVALUATION_IMPLICIT"); //$NON-NLS-1$
+ } else {
+ buf.append(fEvaluationDetail);
+ }
+ buf.append(" Hit Breakpoints: "); //$NON-NLS-1$
+ buf.append(fHitBreakpoints);
+ System.out.println(buf.toString());
+ }
EvaluationResult result = new EvaluationResult(ASTEvaluationEngine.this, fExpression.getSnippet(), fThread);
if (fExpression.hasErrors()) {
String[] errors = fExpression.getErrorMessages();
@@ -467,6 +528,18 @@
result.addError(errors[i]);
}
evaluationFinished(result);
+ if (JDIDebugOptions.DEBUG_AST_EVAL) {
+ StringBuffer buf = new StringBuffer();
+ buf.append("\tErrors: "); //$NON-NLS-1$
+ for (int i = 0; i < errors.length; i++) {
+ if (i > 0) {
+ buf.append('\n');
+ }
+ buf.append("\t\t"); //$NON-NLS-1$
+ buf.append(errors[i]);
+ }
+ System.out.println(buf.toString());
+ }
return;
}
final Interpreter interpreter = new Interpreter(fExpression, fContext);
@@ -516,11 +589,13 @@
EvaluationRunnable er = new EvaluationRunnable();
CoreException exception = null;
+ long start = System.currentTimeMillis();
try {
fThread.runEvaluation(er, null, fEvaluationDetail, fHitBreakpoints);
} catch (DebugException e) {
exception = e;
}
+ long end = System.currentTimeMillis();
IJavaValue value = interpreter.getResult();
@@ -530,6 +605,12 @@
result.setTerminated(er.fTerminated);
if (exception != null) {
+ if (JDIDebugOptions.DEBUG_AST_EVAL) {
+ StringBuffer buf = new StringBuffer();
+ buf.append("\tException: "); //$NON-NLS-1$
+ buf.append(exception.toString());
+ System.out.println(buf.toString());
+ }
if (exception instanceof DebugException) {
result.setException((DebugException)exception);
} else {
@@ -538,11 +619,24 @@
} else {
if (value != null) {
result.setValue(value);
+ if (JDIDebugOptions.DEBUG_AST_EVAL) {
+ StringBuffer buf = new StringBuffer();
+ buf.append("\tResult: "); //$NON-NLS-1$
+ buf.append(value);
+ System.out.println(buf.toString());
+ }
} else {
result.addError(EvaluationEngineMessages.ASTEvaluationEngine_An_unknown_error_occurred_during_evaluation);
}
}
+ if (JDIDebugOptions.DEBUG_AST_EVAL) {
+ StringBuffer buf = new StringBuffer();
+ buf.append("\tDuration: "); //$NON-NLS-1$
+ buf.append(end - start);
+ buf.append("ms"); //$NON-NLS-1$
+ System.out.println(buf.toString());
+ }
evaluationFinished(result);
}
diff --git a/org.eclipse.jdt.debug/jdi/org/eclipse/jdi/internal/MirrorImpl.java b/org.eclipse.jdt.debug/jdi/org/eclipse/jdi/internal/MirrorImpl.java
index a2b9053..5946c55 100644
--- a/org.eclipse.jdt.debug/jdi/org/eclipse/jdi/internal/MirrorImpl.java
+++ b/org.eclipse.jdt.debug/jdi/org/eclipse/jdi/internal/MirrorImpl.java
@@ -26,8 +26,6 @@
import org.eclipse.jdi.internal.jdwp.JdwpString;
import org.eclipse.jdt.internal.debug.core.JDIDebugOptions;
-import com.ibm.icu.text.DateFormat;
-import com.ibm.icu.text.SimpleDateFormat;
import com.sun.jdi.ClassNotPreparedException;
import com.sun.jdi.InternalException;
import com.sun.jdi.InvalidStackFrameException;
@@ -56,9 +54,6 @@
/** True if a Jdwp request has been sent to the VM and the response is not yet (fully) processed. */
private boolean fPendingJdwpRequest = false;
- // used for debug messages
- private static final DateFormat LOCAL_SDF = new SimpleDateFormat("yyyy-MM-dd HH:mm:ss.SSS"); //$NON-NLS-1$
-
/**
* Constructor only to be used by Virtual Machine objects: stores description of Mirror object and Virtual Machine.
*/
@@ -183,7 +178,7 @@
long recieved = System.currentTimeMillis();
if (JDIDebugOptions.DEBUG_JDI_REQUEST_TIMES) {
StringBuffer buf = new StringBuffer();
- buf.append(LOCAL_SDF.format(new Date(sent)));
+ buf.append(JDIDebugOptions.FORMAT.format(new Date(sent)));
buf.append(" JDI Request: "); //$NON-NLS-1$
buf.append(commandPacket.toString());
buf.append("\n\tResponse Time: "); //$NON-NLS-1$
diff --git a/org.eclipse.jdt.debug/model/org/eclipse/jdt/internal/debug/core/JDIDebugOptions.java b/org.eclipse.jdt.debug/model/org/eclipse/jdt/internal/debug/core/JDIDebugOptions.java
index 8d484cf..70e2a9f 100644
--- a/org.eclipse.jdt.debug/model/org/eclipse/jdt/internal/debug/core/JDIDebugOptions.java
+++ b/org.eclipse.jdt.debug/model/org/eclipse/jdt/internal/debug/core/JDIDebugOptions.java
@@ -12,6 +12,9 @@
import org.eclipse.core.runtime.Platform;
+import com.ibm.icu.text.DateFormat;
+import com.ibm.icu.text.SimpleDateFormat;
+
/**
* Debug flags in options file.
*
@@ -22,6 +25,11 @@
public static boolean DEBUG = false;
public static boolean DEBUG_JDI_EVENTS = false;
public static boolean DEBUG_JDI_REQUEST_TIMES = false;
+ public static boolean DEBUG_AST_EVAL = false;
+ public static boolean DEBUG_AST_EVAL_THREAD_TRACE = false;
+
+ // used to format debug messages
+ public static final DateFormat FORMAT = new SimpleDateFormat("yyyy-MM-dd HH:mm:ss.SSS"); //$NON-NLS-1$
public static void initDebugOptions() {
DEBUG = "true".equals(Platform.getDebugOption("org.eclipse.jdt.debug/debug")); //$NON-NLS-1$//$NON-NLS-2$
@@ -29,5 +37,9 @@
Platform.getDebugOption("org.eclipse.jdt.debug/debug/jdiEvents")); //$NON-NLS-1$
DEBUG_JDI_REQUEST_TIMES = DEBUG && "true".equals( //$NON-NLS-1$
Platform.getDebugOption("org.eclipse.jdt.debug/debug/jdiRequestTimes")); //$NON-NLS-1$
+ DEBUG_AST_EVAL = DEBUG && "true".equals( //$NON-NLS-1$
+ Platform.getDebugOption("org.eclipse.jdt.debug/debug/astEvaluations")); //$NON-NLS-1$
+ DEBUG_AST_EVAL_THREAD_TRACE = DEBUG && "true".equals( //$NON-NLS-1$
+ Platform.getDebugOption("org.eclipse.jdt.debug/debug/astEvaluations/callingThreads")); //$NON-NLS-1$
}
}
