Bug 150487 "Tracing and Logging Framework" (WeavingAdaptorMessageHandler delegates and traces)

6 files changed, 173 insertions, 50 deletions

diff --git a/loadtime/src/org/aspectj/weaver/loadtime/ClassLoaderWeavingAdaptor.java b/loadtime/src/org/aspectj/weaver/loadtime/ClassLoaderWeavingAdaptor.java
index 161c8f62f..d43034c90 100644
--- a/loadtime/src/org/aspectj/weaver/loadtime/ClassLoaderWeavingAdaptor.java
+++ b/loadtime/src/org/aspectj/weaver/loadtime/ClassLoaderWeavingAdaptor.java
@@ -124,8 +124,8 @@ public class ClassLoaderWeavingAdaptor extends WeavingAdaptor {
         };
 
         List definitions = parseDefinitions(classLoader);
-        if (!enabled) {
-        	if (trace.isTraceEnabled()) trace.exit("initialize",enabled);
+        if (!isEnabled()) {
+        	if (trace.isTraceEnabled()) trace.exit("initialize",false);
         	return;
         }
         
@@ -147,7 +147,7 @@ public class ClassLoaderWeavingAdaptor extends WeavingAdaptor {
 
         // register the definitions
         registerDefinitions(weaver, classLoader, definitions);
-        if (enabled) {
+        if (isEnabled()) {
 
             //bcelWorld.setResolutionLoader(loader.getParent());//(ClassLoader)null);//
             
@@ -160,7 +160,7 @@ public class ClassLoaderWeavingAdaptor extends WeavingAdaptor {
         }
         
         initialized = true;
-    	if (trace.isTraceEnabled()) trace.exit("initialize",enabled);
+    	if (trace.isTraceEnabled()) trace.exit("initialize",isEnabled());
     }
 
     /**
@@ -198,11 +198,11 @@ public class ClassLoaderWeavingAdaptor extends WeavingAdaptor {
     			}
     		}
     		if (definitions.isEmpty()) {
-                enabled = false;// will allow very fast skip in shouldWeave()
+                disable();// will allow very fast skip in shouldWeave()
         		info("no configuration found. Disabling weaver for class loader " + getClassLoaderName(loader));
     		}
         } catch (Exception e) {
-            enabled = false;// will allow very fast skip in shouldWeave()
+            disable();// will allow very fast skip in shouldWeave()
             warn("parse definitions failed",e);
         }
 		return definitions;
@@ -217,7 +217,7 @@ public class ClassLoaderWeavingAdaptor extends WeavingAdaptor {
             registerIncludeExclude(weaver, loader, definitions);
             registerDump(weaver, loader, definitions);
         } catch (Exception e) {
-            enabled = false;// will allow very fast skip in shouldWeave()
+            disable();// will allow very fast skip in shouldWeave()
             warn("register definition failed",(e instanceof AbortException)?null:e);
         }
     }
@@ -341,7 +341,7 @@ public class ClassLoaderWeavingAdaptor extends WeavingAdaptor {
     	kind.signal(infos,null,null);
     }
 	
-	protected String getContextId () {
+	public String getContextId () {
 		return weavingContext.getId();
 	}
     
@@ -413,11 +413,11 @@ public class ClassLoaderWeavingAdaptor extends WeavingAdaptor {
         
         /* We didn't register any aspects so disable the adaptor */
         if (namespace == null) {
-        	enabled = false;
+        	disable();
     		info("no aspects registered. Disabling weaver for class loader " + getClassLoaderName(loader));
         }
 
-        if (trace.isTraceEnabled()) trace.exit("registerAspects",enabled);
+        if (trace.isTraceEnabled()) trace.exit("registerAspects",isEnabled());
     }
 
     /**
@@ -697,4 +697,4 @@ public class ClassLoaderWeavingAdaptor extends WeavingAdaptor {
 
 		if (trace.isTraceEnabled()) trace.exit("defineClass",clazz);
 	}
-}
+}
\ No newline at end of file
diff --git a/tests/src/org/aspectj/systemtest/tracing/TracingTests.java b/tests/src/org/aspectj/systemtest/tracing/TracingTests.java
index e782e0887..1eb7924bf 100644
--- a/tests/src/org/aspectj/systemtest/tracing/TracingTests.java
+++ b/tests/src/org/aspectj/systemtest/tracing/TracingTests.java
@@ -34,8 +34,8 @@ public class TracingTests extends org.aspectj.testing.XMLBasedAjcTestCase {
   		runTest("Default tracing");
 	}
 	
-	public void testDefaultTracingMessageHandler () {
-  		runTest("Default TraceMessageHandler");
+	public void testTraceMessages () {
+  		runTest("Trace messages");
 	}
 
 }
diff --git a/tests/src/org/aspectj/systemtest/tracing/tracing.xml b/tests/src/org/aspectj/systemtest/tracing/tracing.xml
index b0dca8d8c..a9f64bd69 100644
--- a/tests/src/org/aspectj/systemtest/tracing/tracing.xml
+++ b/tests/src/org/aspectj/systemtest/tracing/tracing.xml
@@ -7,35 +7,54 @@
         <compile
         	files="TracingTest.java"
         />
-        <ant file="ant.xml" target="Tracing" verbose="true"/>
+        <ant file="ant.xml" target="Tracing" verbose="true">
+        	<stdout>
+                <line text="? TracingTest.main() trace="/>
+            </stdout>
+		</ant>      
     </ajc-test>
 
 	<ajc-test dir="tracing" title="Default tracing" keywords="tracing">
         <compile
         	files="DefaultTracingTest.java"
         />
-        <ant file="ant.xml" target="Default tracing" verbose="true"/>
+        <ant file="ant.xml" target="Default tracing" verbose="true">
+        	<stdout>
+                <line text="? DefaultTracingTest.main() trace=org.aspectj.weaver.tools.DefaultTrace"/>
+            </stdout>
+		</ant>        
     </ajc-test>
 
-	<ajc-test dir="tracing" title="Default TraceMessageHandler" keywords="tracing">
+	<ajc-test dir="tracing" title="Trace messages" keywords="tracing">
         <compile
-        	files="HelloWorld.java, MyDefaultTraceMessageHandler.java"
+        	files="HelloWorld.java"
         />
         <compile
         	files="IncludedAspect.aj, ExcludedAspect.aj"
         />
-        <run class="HelloWorld" ltw="aop-defaulttracemessagehandler.xml">
+		<ant file="ant.xml" target="Trace messages" verbose="true">
         	<stdout>
                 <line text="Hello World!"/>
             </stdout>
+            <!-- 
+            	Always get info messages even without -verbose because output determined
+                by tracing infrastructure.
+                 
+                Duplicate warning and error messages: first through trace then message 
+                writer
+            -->
         	<stderr>
+	  	    	<line text="info AspectJ Weaver Version DEVELOPMENT built on"/>
+	  	    	<line text="info register classloader"/>
+	  	    	<line text="info using configuration"/>
 	  	    	<line text="info register aspect IncludedAspect"/>
 	  	    	<line text="warning aspect ExcludedAspect exluded"/>
+	  	    	<line text="warning aspect ExcludedAspect exluded"/>
+	  	    	<line text="error Cannot find m_parent aspect"/>
 	  	    	<line text="error Cannot find m_parent aspect"/>
-	  	    	<line text="error Concrete-aspect 'IncludedMissingAspect' could not be registered"/>
-	  	    	<line text="info weaving 'HelloWorld'"/>
+	  	    	<line text="warning register definition failed"/>
+	  	    	<line text="warning register definition failed"/>
             </stderr>
-        </run>
+        </ant>
     </ajc-test>
-
 </suite>
diff --git a/tests/tracing/ant.xml b/tests/tracing/ant.xml
index f7852949e..b0b7a9e17 100644
--- a/tests/tracing/ant.xml
+++ b/tests/tracing/ant.xml
@@ -24,4 +24,17 @@
         </java>
     </target>
 
+    <target name="Trace messages">
+        <copy file="${aj.root}/tests/tracing/aop-tracemessages.xml"
+              tofile="${aj.sandbox}/META-INF/aop.xml"/>
+        <java fork="yes" classname="HelloWorld" failonerror="yes">
+            <classpath refid="aj.path"/>
+            <jvmarg value="-Dorg.aspectj.tracing.factory=default"/>
+            <jvmarg value="-Dorg.aspectj.tracing.messages=true"/>
+            <!-- use META-INF/aop.xml style -->
+            <jvmarg value="-javaagent:${aj.root}/lib/test/loadtime5.jar"/>
+<!--            <jvmarg line="${jdwp}"/>-->
+        </java>
+    </target>
+
 </project>
diff --git a/tests/tracing/aop-tracemessages.xml b/tests/tracing/aop-tracemessages.xml
new file mode 100644
index 000000000..4f5e36a5a
--- /dev/null
+++ b/tests/tracing/aop-tracemessages.xml
@@ -0,0 +1,13 @@
+<aspectj>
+	<aspects>
+		<aspect name="IncludedAspect"/>
+		<aspect name="ExcludedAspect"/>
+		
+        <concrete-aspect name="IncludedMissingAspect" extends="MissingAbstractAspect">
+        	<pointcut name="pointcut" expression="within(*)"/>
+        </concrete-aspect>
+		
+		<include within="Included*"/>
+	</aspects>
+    <weaver options="-Xlint:warning"/>
+</aspectj>
\ No newline at end of file
diff --git a/weaver/src/org/aspectj/weaver/tools/WeavingAdaptor.java b/weaver/src/org/aspectj/weaver/tools/WeavingAdaptor.java
index dc7cb73fa..3d80b9901 100644
--- a/weaver/src/org/aspectj/weaver/tools/WeavingAdaptor.java
+++ b/weaver/src/org/aspectj/weaver/tools/WeavingAdaptor.java
@@ -31,11 +31,13 @@ import java.util.StringTokenizer;
 
 import org.aspectj.bridge.AbortException;
 import org.aspectj.bridge.IMessage;
+import org.aspectj.bridge.IMessageContext;
 import org.aspectj.bridge.IMessageHandler;
 import org.aspectj.bridge.Message;
 import org.aspectj.bridge.MessageUtil;
 import org.aspectj.bridge.MessageWriter;
 import org.aspectj.bridge.Version;
+import org.aspectj.bridge.WeaveMessage;
 import org.aspectj.bridge.IMessage.Kind;
 import org.aspectj.org.objectweb.asm.ClassReader;
 import org.aspectj.util.FileUtil;
@@ -63,15 +65,16 @@ import org.aspectj.weaver.bcel.Utility;
  * weaving messages to be written to the console.
  *
  */
-public class WeavingAdaptor {
+public class WeavingAdaptor implements IMessageContext {
 
 	/**
 	 * System property used to turn on verbose weaving messages 
 	 */
 	public static final String WEAVING_ADAPTOR_VERBOSE = "aj.weaving.verbose"; 
 	public static final String SHOW_WEAVE_INFO_PROPERTY = "org.aspectj.weaver.showWeaveInfo"; 
+	public static final String TRACE_MESSAGES_PROPERTY = "org.aspectj.tracing.messages";
 
-	protected boolean enabled = true;
+	private boolean enabled = true;
 	protected boolean verbose = getVerbose();
 	protected BcelWorld bcelWorld;
 	protected BcelWeaver weaver;
@@ -179,12 +182,21 @@ public class WeavingAdaptor {
 	}
 	
 	protected void setMessageHandler (IMessageHandler mh) {
-		if (messageHolder != null) {
-			messageHolder.flushMessages();
-			messageHolder = null;
+		if (mh instanceof ISupportsMessageContext) {
+			ISupportsMessageContext smc = (ISupportsMessageContext)mh;
+			smc.setMessageContext(this);
 		}
-		messageHandler = mh;
-		bcelWorld.setMessageHandler(mh);
+		if (mh != messageHolder) messageHolder.setDelegate(mh);
+		messageHolder.flushMessages();
+	}
+	
+	protected void disable () {
+		enabled = false;
+		messageHolder.flushMessages();
+	}
+	
+	protected boolean isEnabled () {
+		return enabled;
 	}
 	
 	/**
@@ -396,7 +408,7 @@ public class WeavingAdaptor {
 		return MessageUtil.error(messageHandler,message);
 	}
 	
-	protected String getContextId () {
+	public String getContextId () {
 		return "WeavingAdaptor";
 	}
 
@@ -436,14 +448,97 @@ public class WeavingAdaptor {
 	 * Processes messages arising from weaver operations. 
 	 * Tell weaver to abort on any message more severe than warning.
 	 */
-	protected class WeavingAdaptorMessageHandler extends MessageWriter {
+	protected class WeavingAdaptorMessageHandler implements IMessageHandler {
 
-		private Set ignoring = new HashSet();
-		private IMessage.Kind failKind;
+		private IMessageHandler delegate;
 		private boolean accumulating = true;
 	    private List messages = new ArrayList();
 
+		protected boolean traceMessages = Boolean.getBoolean(TRACE_MESSAGES_PROPERTY);
+	    
 		public WeavingAdaptorMessageHandler (PrintWriter writer) {
+			
+			this.delegate = new WeavingAdaptorMessageWriter(writer);
+		}
+
+		public boolean handleMessage(IMessage message) throws AbortException {
+			if (traceMessages) traceMessage(message);
+			if (accumulating) {
+				boolean result = addMessage(message);
+				if (0 <= message.getKind().compareTo(IMessage.ERROR)) {
+					throw new AbortException(message);
+				}
+				return result;
+			}
+			else return delegate.handleMessage(message);
+		}
+		
+		private void traceMessage (IMessage message) {
+			if (message instanceof WeaveMessage) {
+				trace.debug(render(message));
+			}
+			else if (message.isDebug()) {
+				trace.debug(render(message));
+			}
+			else if (message.isInfo()) {
+				trace.info(render(message));
+			}
+			else if (message.isWarning()) {
+				trace.warn(render(message),message.getThrown());
+			}
+			else if (message.isError()) {
+				trace.error(render(message),message.getThrown());
+			}
+			else if (message.isFailed()) {
+				trace.fatal(render(message),message.getThrown());
+			}
+			else if (message.isAbort()) {
+				trace.fatal(render(message),message.getThrown());
+			}
+			else {
+				trace.error(render(message),message.getThrown());
+			}
+		}
+
+	    protected String render(IMessage message) {
+	    	return "[" + getContextId() + "] " + message.toString();    
+	    }
+
+		public boolean isIgnoring (Kind kind) {
+			return delegate.isIgnoring(kind);
+		}
+
+		public void dontIgnore (IMessage.Kind kind) {
+			if (null != kind) {
+				delegate.dontIgnore(kind);
+			}
+		}
+		
+		private boolean addMessage (IMessage message) {
+			messages.add(message);
+			return true;
+		}
+		
+		public void flushMessages () {
+            for (Iterator iter = messages.iterator(); iter.hasNext();) {
+                IMessage message = (IMessage)iter.next();
+                delegate.handleMessage(message);
+            }
+			accumulating = false;
+			messages.clear();
+		}
+		
+		public void setDelegate (IMessageHandler messageHandler) {
+			delegate = messageHandler;
+		}
+	}
+
+	protected class WeavingAdaptorMessageWriter extends MessageWriter {
+
+		private Set ignoring = new HashSet();
+		private IMessage.Kind failKind;
+
+		public WeavingAdaptorMessageWriter (PrintWriter writer) {
 			super(writer,true);
 			
 			ignore(IMessage.WEAVEINFO);
@@ -452,7 +547,6 @@ public class WeavingAdaptor {
 		}
 
 		public boolean handleMessage(IMessage message) throws AbortException {
-			addMessage(message);
 			boolean result = super.handleMessage(message);
 			if (0 <= message.getKind().compareTo(failKind)) {
 				throw new AbortException(message);
@@ -479,24 +573,8 @@ public class WeavingAdaptor {
 		public void dontIgnore (IMessage.Kind kind) {
 			if (null != kind) {
 				ignoring.remove(kind);
-				if (kind.equals(IMessage.INFO)) accumulating = false;
-			}
-		}
-		
-		private void addMessage (IMessage message) {
-			if (accumulating && isIgnoring(message.getKind())) {
-				messages.add(message);
 			}
 		}
-		
-		public void flushMessages () {
-            for (Iterator iter = messages.iterator(); iter.hasNext();) {
-                IMessage message = (IMessage)iter.next();
-                super.handleMessage(message);
-            }
-			accumulating = false;
-			messages.clear();
-		}
 
 	    protected String render(IMessage message) {
 	    	return "[" + getContextId() + "] " + super.render(message);