[280947] Adding debug traces to the CommandCache

dsf-gdb/org.eclipse.cdt.dsf.gdb/src/org/eclipse/cdt/dsf/mi/service/command/AbstractMIControl.java

@@ -67,6 +67,8 @@ import org.eclipse.core.runtime.Status;
 public abstract class AbstractMIControl extends AbstractDsfService
     implements ICommandControlService
 {
+	private static final String MI_TRACE_IDENTIFIER = " [MI]  "; //$NON-NLS-1$
+	
     /*
 	 *  Thread control variables for the transmit and receive threads.
 	 */
@@ -549,7 +551,7 @@ public abstract class AbstractMIControl extends AbstractDsfService
                         fOutputStream.write(str.getBytes());
                         fOutputStream.flush();
 
-                        GdbPlugin.debug(GdbPlugin.getDebugTime() + " " + str); //$NON-NLS-1$
+                        GdbPlugin.debug(GdbPlugin.getDebugTime() + MI_TRACE_IDENTIFIER + str);
                         getExecutor().execute(new DsfRunnable() {
                         	public void run() {
                         		if (getMITracingStream() != null) {
@@ -601,7 +603,7 @@ public abstract class AbstractMIControl extends AbstractDsfService
                 String line;
                 while ((line = reader.readLine()) != null) {
                     if (line.length() != 0) {
-                        GdbPlugin.debug(GdbPlugin.getDebugTime() + " " + line +"\n"); //$NON-NLS-1$ //$NON-NLS-2$
+                        GdbPlugin.debug(GdbPlugin.getDebugTime() + MI_TRACE_IDENTIFIER + line + "\n"); //$NON-NLS-1$
                         
                         final String finalLine = line;
                         getExecutor().execute(new DsfRunnable() {

dsf-gdb/org.eclipse.cdt.dsf.gdb/src/org/eclipse/cdt/dsf/mi/service/command/commands/ExprMetaCommand.java

@@ -10,7 +10,9 @@
  *******************************************************************************/
 package org.eclipse.cdt.dsf.mi.service.command.commands;
 
+import org.eclipse.cdt.dsf.datamodel.DMContexts;
 import org.eclipse.cdt.dsf.datamodel.IDMContext;
+import org.eclipse.cdt.dsf.debug.service.IExpressions.IExpressionDMContext;
 import org.eclipse.cdt.dsf.debug.service.command.ICommand;
 import org.eclipse.cdt.dsf.debug.service.command.ICommandResult;
 
@@ -52,7 +54,13 @@ public class ExprMetaCommand<V extends ICommandResult> implements ICommand<V> {
     
     @Override
     public String toString() {
-        return getClass().getName() + (fCtx == null ? "null" : fCtx.toString()); //$NON-NLS-1$
+    	IExpressionDMContext exprDmc = DMContexts.getAncestorOfType(fCtx, IExpressionDMContext.class);
+    	if (exprDmc != null) {
+    		return getClass().getSimpleName() + "(\"" + //$NON-NLS-1$
+    				exprDmc.getExpression() + "\")"; //$NON-NLS-1$
+    	} else {
+    		return getClass().getName() + (fCtx == null ? "null" : fCtx.toString()); //$NON-NLS-1$
+    	}
     }
     
     public String getCommandControlFilter() {

dsf-gdb/org.eclipse.cdt.dsf.gdb/src/org/eclipse/cdt/dsf/mi/service/command/commands/ExprMetaGetValue.java

@@ -10,6 +10,8 @@
  *******************************************************************************/
 package org.eclipse.cdt.dsf.mi.service.command.commands;
 
+import org.eclipse.cdt.dsf.datamodel.DMContexts;
+import org.eclipse.cdt.dsf.debug.service.IExpressions.IExpressionDMContext;
 import org.eclipse.cdt.dsf.debug.service.IFormattedValues.FormattedValueDMContext;
 import org.eclipse.cdt.dsf.mi.service.command.output.ExprMetaGetValueInfo;
 
@@ -18,4 +20,16 @@ public class ExprMetaGetValue extends ExprMetaCommand<ExprMetaGetValueInfo> {
 	public ExprMetaGetValue(FormattedValueDMContext ctx) {
 		super(ctx);
 	}
+	
+    @Override
+    public String toString() {
+    	IExpressionDMContext exprDmc = DMContexts.getAncestorOfType(getContext(), IExpressionDMContext.class);
+    	if (exprDmc != null) {
+    		return getClass().getSimpleName() + "(\"" + //$NON-NLS-1$
+    				exprDmc.getExpression() + "\", " + //$NON-NLS-1$
+    				((FormattedValueDMContext)getContext()).getFormatID() + ")"; //$NON-NLS-1$
+    	} else {
+    		return super.toString();
+    	}
+    }
 }

dsf-gdb/org.eclipse.cdt.dsf.gdb/src/org/eclipse/cdt/dsf/mi/service/command/output/ExprMetaGetAttributesInfo.java

@@ -26,4 +26,9 @@ public class ExprMetaGetAttributesInfo implements ICommandResult {
 	public <V extends ICommandResult> V getSubsetResult(ICommand<V> command) {
 		return null;
 	}
+
+	@Override
+	public String toString() {
+		return getClass().getSimpleName() + " (" + getEditable() + ")"; //$NON-NLS-1$ //$NON-NLS-2$
+	}
 }

dsf-gdb/org.eclipse.cdt.dsf.gdb/src/org/eclipse/cdt/dsf/mi/service/command/output/ExprMetaGetChildCountInfo.java

@@ -26,4 +26,9 @@ public class ExprMetaGetChildCountInfo implements ICommandResult {
 	public <V extends ICommandResult> V getSubsetResult(ICommand<V> command) {
 		return null;
 	}
+	
+	@Override
+	public String toString() {
+		return getClass().getSimpleName() + " (" + getChildNum() + ")"; //$NON-NLS-1$ //$NON-NLS-2$
+	}
 }

dsf-gdb/org.eclipse.cdt.dsf.gdb/src/org/eclipse/cdt/dsf/mi/service/command/output/ExprMetaGetChildrenInfo.java

@@ -27,4 +27,11 @@ public class ExprMetaGetChildrenInfo implements ICommandResult {
 	public <V extends ICommandResult> V getSubsetResult(ICommand<V> command) {
 		return null;
 	}
+	
+	@Override
+	public String toString() {
+		return getClass().getSimpleName() + " [Array of " +  //$NON-NLS-1$
+				(getChildrenExpressions() == null ? 0 : getChildrenExpressions().length) +
+				" children]"; //$NON-NLS-1$
+	}
 }

dsf-gdb/org.eclipse.cdt.dsf.gdb/src/org/eclipse/cdt/dsf/mi/service/command/output/ExprMetaGetValueInfo.java

@@ -26,4 +26,9 @@ public class ExprMetaGetValueInfo implements ICommandResult {
 		public <V extends ICommandResult> V getSubsetResult(ICommand<V> command) {
 			return null;
 		}
+		
+		@Override
+		public String toString() {
+			return getClass().getSimpleName() + " (" + getValue() + ")"; //$NON-NLS-1$ //$NON-NLS-2$
+		}
 	}

dsf-gdb/org.eclipse.cdt.dsf.gdb/src/org/eclipse/cdt/dsf/mi/service/command/output/ExprMetaGetVarInfo.java

@@ -35,4 +35,11 @@ public class ExprMetaGetVarInfo implements ICommandResult {
 	public <V extends ICommandResult> V getSubsetResult(ICommand<V> command) {
 		return null;
 	}
+
+	@Override
+	public String toString() {
+		return getClass().getSimpleName() + " (" + //$NON-NLS-1$ 
+				getExpr() + ", " + getNumChildren() + ", " +  //$NON-NLS-1$ //$NON-NLS-2$
+				getType() + ", " + getEditable() + ")"; //$NON-NLS-1$ //$NON-NLS-2$
+	}
 }

dsf/org.eclipse.cdt.dsf/.options

@@ -1,3 +1,4 @@
 org.eclipse.cdt.dsf/debug = false
 org.eclipse.cdt.dsf/debug/executor = false
 org.eclipse.cdt.dsf/debug/executorName = 
+org.eclipse.cdt.dsf/debugCache = false

dsf/org.eclipse.cdt.dsf/src/org/eclipse/cdt/dsf/debug/service/command/CommandCache.java

@@ -28,6 +28,7 @@ import org.eclipse.cdt.dsf.datamodel.IDMContext;
 import org.eclipse.cdt.dsf.internal.DsfPlugin;
 import org.eclipse.cdt.dsf.service.DsfSession;
 import org.eclipse.core.runtime.IStatus;
+import org.eclipse.core.runtime.Platform;
 import org.eclipse.core.runtime.Status;
 
 /**
@@ -158,6 +159,56 @@ public class CommandCache implements ICommandListener
     
     private ArrayList<CommandInfo> fPendingQWaitingForCoalescedCompletion = new ArrayList<CommandInfo>();
     
+    private static boolean DEBUG = false;
+	private static final String CACHE_TRACE_IDENTIFIER = " [CHE]"; //$NON-NLS-1$
+	private static String BLANK_CACHE_TRACE_IDENTIFIER = ""; //$NON-NLS-1$
+	static {
+        DEBUG = "true".equals(Platform.getDebugOption("org.eclipse.cdt.dsf/debugCache"));  //$NON-NLS-1$//$NON-NLS-2$
+		for (int i=0; i<CACHE_TRACE_IDENTIFIER.length(); i++) {
+			BLANK_CACHE_TRACE_IDENTIFIER += " "; //$NON-NLS-1$
+		}
+    }  
+
+	private void debug(String message) {
+		debug(message, ""); //$NON-NLS-1$
+    }
+    
+    private void debug(String message, String prefix) {
+    	if (DEBUG) {
+    		// The message can span more than one line
+    		String[] multiLine = message.split("\n"); //$NON-NLS-1$
+    		
+			// Create a blank prefix for proper alignment
+    		String blankPrefix = ""; //$NON-NLS-1$
+    		for (int i=0; i<prefix.length(); i++) {
+    			blankPrefix += " "; //$NON-NLS-1$
+    		}
+
+    		for (int i = 0; i < multiLine.length; i++) {
+    			String traceIdentifier;
+    			if (i == 0) {
+    	    		// For the first line we prepend the cache identifier string
+    				traceIdentifier = CACHE_TRACE_IDENTIFIER + prefix;
+    				
+    			} else {
+    	    		// For all other lines we prepend a blank prefix for proper alignment
+    				traceIdentifier = BLANK_CACHE_TRACE_IDENTIFIER + blankPrefix;
+    			}
+    				
+    			message = DsfPlugin.getDebugTime() + traceIdentifier + 
+    						" " + multiLine[i]; //$NON-NLS-1$
+
+    			// Make sure our lines are not too long
+    			while (message.length() > 100) {
+    				String partial = message.substring(0, 100) + "\\"; //$NON-NLS-1$
+    				message = message.substring(100);
+    				System.out.println(partial);
+    			}
+    			System.out.println(message);
+    		}
+    	}
+    }
+
     public CommandCache(DsfSession session, ICommandControl control) {
         fSession = session;
         fCommandControl = control;
@@ -256,12 +307,15 @@ public class CommandCache implements ICommandListener
          */ 
         if(fCachedContexts.get(context) != null && fCachedContexts.get(context).containsKey(cachedCmd)){
         	CommandResultInfo result = fCachedContexts.get(context).get(cachedCmd);
+        	debug(command.toString().trim());
             if (result.getStatus().getSeverity() <= IStatus.INFO) {
             	@SuppressWarnings("unchecked") 
             	V v = (V)result.getData();
             	rm.setData(v);
+            	debug(v.toString());
             } else {
             	rm.setStatus(result.getStatus());
+            	debug(result.getStatus().toString());
             }
             rm.done();
             return;
@@ -271,6 +325,8 @@ public class CommandCache implements ICommandListener
          *  Return an error if the target is available anymore.
          */ 
         if (!isTargetAvailable(command.getContext())) {
+        	debug(command.toString().trim(), "[N/A]"); //$NON-NLS-1$
+
             rm.setStatus(new Status(IStatus.ERROR, DsfPlugin.PLUGIN_ID, IDsfStatusConstants.INVALID_STATE, "Target not available.", null)); //$NON-NLS-1$
             rm.done();
             return;
@@ -283,12 +339,14 @@ public class CommandCache implements ICommandListener
         for ( CommandInfo sentCommand : fPendingQCommandsSent ) {
             if ( sentCommand.equals( cachedCmd )) {
                 sentCommand.getRequestMonitorList().add(genericDone);
+            	debug(command.toString().trim(), "[SNT]"); //$NON-NLS-1$
                 return;
             }
         }
         for ( CommandInfo notYetSentCommand : fPendingQCommandsNotYetSent ) {
             if ( notYetSentCommand.equals( cachedCmd )) {
                 notYetSentCommand.getRequestMonitorList().add(genericDone);
+            	debug(command.toString().trim(), "[SND]"); //$NON-NLS-1$
                 return;
             }
         }