Commits

tbrugz  committed bec0efb

added properties/event debuggers: 'mon.thread' & 'mon.exception'

  • Participants
  • Parent commits 67500dc

Comments (0)

Files changed (5)

File README.markdown

 - jdk 1.5 (especially "jdk.home"/lib/tools.jar)
 
 
+Running Options
+---------------
+
+The following system properties may be set for extra debugging:
+
+- `mon.thread` - monitors thread start & thread death events
+- `mon.exception` - monitors exception events
+
+
 Usage
 -----
-`java -cp rt-coverage.jar;commons-logging-1.1.1.jar;log4j-1.2.15.jar;<jdk.home>/lib/tools.jar tbrugz.rtcoverage.RuntimeCoverage <your.package.MainClass>`
+`java <system-properties> -cp rt-coverage.jar;commons-logging-1.1.1.jar;log4j-1.2.15.jar;<jdk.home>/lib/tools.jar tbrugz.rtcoverage.RuntimeCoverage <your.package.MainClass>`
 
 example:
-`java -cp rt-coverage.jar;commons-logging-1.1.1.jar;log4j-1.2.15.jar;tools.jar tbrugz.rtcoverage.RuntimeCoverage -cp dist/rt-coverage-test.jar tbrugz.rtcoverage.test.DivAurea`
+`java -Dmon.thread -cp rt-coverage.jar;commons-logging-1.1.1.jar;log4j-1.2.15.jar;tools.jar tbrugz.rtcoverage.RuntimeCoverage -cp dist/rt-coverage-test.jar tbrugz.rtcoverage.test.DivAurea`
 
 or take a look at `build.xml`: `run-rt-coverage`

File src/log4j.properties

 # exception logging
 log4j.logger.tbrugz.rtcoverage.JDIEventProcessor.ex=DEBUG
 
+# control classes
+log4j.logger.tbrugz.rtcoverage.RuntimeCoverage=DEBUG
+log4j.logger.tbrugz.rtcoverage.JDIEventProcessor=DEBUG
+
 ################
 
 # Appender A1 - default
 log4j.appender.A1.layout=org.apache.log4j.PatternLayout
 # Print the date in ISO 8601 format
 # log4j.appender.A1.layout.ConversionPattern=%d [%t] %-5p %c - %m%n
-log4j.appender.A1.layout.ConversionPattern=[%p] %m%n
+log4j.appender.A1.layout.ConversionPattern=%-6r [%p] %m%n
 log4j.appender.A1.target=System.out
 
 # Appender A2 - analysis

File src/tbrugz/rtcoverage/JDIEventProcessor.java

 import com.sun.jdi.InvalidTypeException;
 import com.sun.jdi.InvocationException;
 import com.sun.jdi.Method;
+import com.sun.jdi.ObjectCollectedException;
 import com.sun.jdi.ObjectReference;
 import com.sun.jdi.ReferenceType;
 import com.sun.jdi.StringReference;
             do {
                 EventSet eventSet = eventQueue.remove();
                 long eventIniTime = System.currentTimeMillis();
+                //int resumeVMtimes = 0;
                 for(EventIterator i = eventSet.eventIterator(); i.hasNext(); ) {
                     Event evt = i.nextEvent();
                     if(evt instanceof ClassPrepareEvent) {
                     	logClazz.debug("Unloading: " + cue.className());
                     } else if(evt instanceof ThreadStartEvent) {
                     	ThreadStartEvent tse = (ThreadStartEvent) evt;
-                    	logThread.debug("Thread Start: " + tse.thread().name());
+                    	threadEventDebug(tse.thread(), "Thread Start");
+                    	//logThread.debug("Thread Start: " + tse.thread().name());
                     } else if(evt instanceof ThreadDeathEvent) {
                     	ThreadDeathEvent tde = (ThreadDeathEvent) evt;
-                    	logThread.debug("Thread Death: " + tde.thread().name());
-                        //SuspendVMTimed svt = new SuspendVMTimed(tde.virtualMachine(), 1000);
+                    	threadEventDebug(tde.thread(), "Thread Death");
+                    	//resumeVMtimes++;
+                    	//tde.virtualMachine().resume();
+                    	//logThread.debug("Thread Death: " + tde.thread().name());
+                    	//SuspendVMTimed svt = new SuspendVMTimed(tde.virtualMachine(), 1000);
                     } else if(evt instanceof ExceptionEvent) {
                     	ExceptionEvent exe = (ExceptionEvent) evt;
-                    	ReferenceType rt = exe.exception().referenceType();
-                    	Field field = rt.fieldByName("detailMessage");
-                    	//detailMessage
-                    	Value v = exe.exception().getValue(field);
-                    	if(exe.catchLocation()!=null) {
-                    		logException.debug("CaughtEx: [" + exe.location() + " / " + exe.catchLocation() + "] "+exe.exception().referenceType().name()+": "+v.toString());
-                    	}
-                    	else {
-                    		logException.debug("UncaughtEx: [" + exe.location() + "] "+exe.exception().referenceType().name()+": "+v.toString());
-                    	}
+                    	exceptionEventDebug(exe);
                     } else if(evt instanceof VMDisconnectEvent) {
                     	log.debug("VMDisconnectEvent!");
-                        stop = true;
+                    	stop = true;
                     }
                 }
                 eventTime += (System.currentTimeMillis() - eventIniTime);
+                //for(int i=0;i<resumeVMtimes;i++) {
+                //	eventQueue.virtualMachine().resume();
+                //}
+            	//resumeVMtimes = 0;
                 eventSet.resume();
+                //eventQueue.virtualMachine().resume();
             } while(!stop);
         }
         catch(Throwable oops) {
         } 
         finally {
         	runningTime = (System.currentTimeMillis()-initTime);
-        	log.info("running time: "+runningTime+"ms ; event threadment time: "+eventTime+
+        	log.info("running time: "+runningTime+"ms ; event treatment time: "+eventTime+
         			" ; ratio: "+((double)eventTime/(double)runningTime));
         	//showJarsUsed();
         }
 			ArrayReference arURLs = (ArrayReference) vURLs;
 			List<Value> values = arURLs.getValues();
 			
+			//XXX: get all StringReferences first, then find() in new thread (so method returns and eventSet may be resumed)
 			for(Value vURL: values) {
 				ObjectReference or = (ObjectReference) vURL; 
 				//logClazz.debug("   u:"+vURL.toString()+"/"+vURL.type());
 				if(pathFound==null) {
 					pathFound = pathFoundTmp;
 				}
+				//XXX: option to not test for shadowed classes (for performance improvement)
 				else {
 					if(pathFoundTmp!=null && !pathFound.equals(pathFoundTmp)) {
 						classesShadowed.add(pathFoundTmp);
 			//classloadersWithNoGetParentMethod.add(classLoaderClassName);
 			log.warn(nsme.getMessage());
 		}
-    }
-    
-    Value simpleInvokeVMMethod(ThreadReference thr, ObjectReference or, String method) throws InvalidTypeException, ClassNotLoadedException, IncompatibleThreadStateException, InvocationException, NoSuchMethodException {
+	}
+	
+	void threadEventDebug(ThreadReference thr, String message) {
+		try {
+			logThread.debug(message+": " + thr.name());
+		}
+		catch(ObjectCollectedException e) {
+			log.warn("objectcollected: "+e);
+		}
+		catch(RuntimeException e) {
+			log.warn("exception: "+e);
+		}
+	}
+	
+	void exceptionEventDebug(ExceptionEvent exc) {
+		try {
+			ReferenceType rt = exc.exception().referenceType();
+			Field field = rt.fieldByName("detailMessage");
+			//detailMessage
+			Value v = exc.exception().getValue(field);
+			if(exc.catchLocation()!=null) {
+				logException.debug("CaughtEx: [" + exc.location() + " | catchLoc: " + exc.catchLocation() + "] "+exc.exception().referenceType().name()+": "+v.toString());
+			}
+			else {
+				logException.debug("UncaughtEx: [" + exc.location() + "] "+exc.exception().referenceType().name()+": "+v.toString());
+			}
+		}
+		catch(RuntimeException e) {
+			log.warn("ExceptionEvent: runtime-exception: "+e);
+		}
+	}
+	
+	//XXX: cache of Method by RT+methodNameString  
+	Value simpleInvokeVMMethod(ThreadReference thr, ObjectReference or, String method) throws InvalidTypeException, ClassNotLoadedException, IncompatibleThreadStateException, InvocationException, NoSuchMethodException {
 		ReferenceType ort = or.referenceType();
     	List<Method> methods = ort.methodsByName(method);
     	if(methods.size()<=0) {

File src/tbrugz/rtcoverage/RuntimeCoverage.java

 //TODO: catch resources loaded by classLoaders, not just classes
 public class RuntimeCoverage {
 
-	static Log log = LogFactory.getLog(RuntimeCoverage.class);
+	static final String PROP_MON_THREAD = "mon.thread";
+	static final String PROP_MON_EXCEPTION = "mon.exception";
+	
+	static final Log log = LogFactory.getLog(RuntimeCoverage.class);
 
 	static final String[] classLoadingExclusionFilters = {
         "java.*",
             Map<String, Connector.Argument> arguments = connector.defaultArguments();
             Connector.Argument mainArgument = arguments.get("main"); 
             StringBuffer mainArgs = new StringBuffer(); 
-            int i;
-            for(i = 0; i < args.length - 1; i++) {
+            for(int i = 0; i < args.length - 1; i++) {
                 mainArgs.append(args[i] + " ");
             }
-            mainArgs.append(args[i]);
+            mainArgs.append(args[args.length-1]);
             mainArgument.setValue(mainArgs.toString());
 
             log.debug("conn: "+connector + " // mainArgs: "+mainArgs.toString()+ " // arguments: " + arguments);
             
             //class prepare
             ClassPrepareRequest cpr = erm.createClassPrepareRequest();
-            for(i = 0; i < classLoadingExclusionFilters.length; i++) {
+            for(int i = 0; i < classLoadingExclusionFilters.length; i++) {
                 cpr.addClassExclusionFilter(classLoadingExclusionFilters[i]);
             }
-            //cpr.setSuspendPolicy(EventRequest.SUSPEND_ALL);
+            //cpr.setSuspendPolicy(EventRequest.SUSPEND_NONE);
             cpr.enable();
+            logEventRequest(cpr);
 
-            /*
             //class unload
             ClassUnloadRequest cur =  erm.createClassUnloadRequest();
-            //cur.enable();
+            for(int i = 0; i < classLoadingExclusionFilters.length; i++) {
+                cur.addClassExclusionFilter(classLoadingExclusionFilters[i]);
+            }
+            cur.setSuspendPolicy(EventRequest.SUSPEND_NONE);
+            cur.enable();
+            logEventRequest(cur);
 
-            //thread start
-            ThreadStartRequest tsr = erm.createThreadStartRequest();
-            //tsr.enable();
+            if(getPropBool(PROP_MON_THREAD)) {
+	            //thread start
+	            ThreadStartRequest tsr = erm.createThreadStartRequest();
+	            tsr.setSuspendPolicy(EventRequest.SUSPEND_NONE);
+	            tsr.enable();
+	            logEventRequest(tsr);
+	
+	            //thread death
+	            ThreadDeathRequest tdr = erm.createThreadDeathRequest();
+	            //tdr.setSuspendPolicy(EventRequest.SUSPEND_ALL);
+	            //tdr.setSuspendPolicy(EventRequest.SUSPEND_EVENT_THREAD);
+	            tdr.setSuspendPolicy(EventRequest.SUSPEND_NONE);
+	            tdr.enable();
+	            logEventRequest(tdr);
+            }
 
-            //thread death
-            ThreadDeathRequest tdr = erm.createThreadDeathRequest();
-            //tdr.setSuspendPolicy(ThreadDeathRequest.SUSPEND_ALL);
-            //tdr.setSuspendPolicy(ThreadDeathRequest.SUSPEND_EVENT_THREAD);
-            //tdr.enable();
-
-            //exception
-            //exception type, caugth, uncaugth
-            ExceptionRequest exr = erm.createExceptionRequest(null, false, true);
-            //exr.enable();
-            */
+            if(getPropBool(PROP_MON_EXCEPTION)) {
+	            //exception
+	            //exception type, caugth, uncaugth
+	            ExceptionRequest exr = erm.createExceptionRequest(null, true, true);
+	            for(int i = 0; i < classLoadingExclusionFilters.length; i++) {
+	                exr.addClassExclusionFilter(classLoadingExclusionFilters[i]);
+	            }
+	            exr.enable();
+	            logEventRequest(exr);
+            }
+            
             
             Thread eventsListener = new JDIEventProcessor(vm.eventQueue());
 
             oops.printStackTrace();
         }
     }
-    
+
+	void logEventRequest(EventRequest er) {
+		String suspendPolicy = null;
+		switch(er.suspendPolicy()) {
+		case EventRequest.SUSPEND_NONE:
+			suspendPolicy = "SUSPEND_NONE"; break;
+		case EventRequest.SUSPEND_EVENT_THREAD:
+			suspendPolicy = "SUSPEND_EVENT_THREAD"; break;
+		case EventRequest.SUSPEND_ALL:
+			suspendPolicy = "SUSPEND_ALL"; break;
+		}
+		log.debug("EventRequest: "+er.getClass().getName()+", suspendPolicy: "+suspendPolicy+", elabled: "+er.isEnabled());
+	}
+	
+	boolean getPropBool(String prop) {
+		if(System.getProperty(prop)!=null) { return true; }
+		return false;
+	}
+	
+	/*void addClassExclusionFilter(EventRequest er) {
+        for(int i = 0; i < classLoadingExclusionFilters.length; i++) {
+            er.addClassExclusionFilter(classLoadingExclusionFilters[i]);
+        }
+	}*/
 }
 -? handle classloaders that doesnt have "getURLs" method
   ex: org.apache.derby.impl.services.reflect.ReflectLoaderJava2
 
-x debug classloaders
+~ debug classloaders
+  - classes unloaded? classes loaded by more than 1 classloader? 
 
 - use rt-coverage as a javaagent (?) / attach to a debuggable jvm
 
 
 ~ show classloader id for earh class loaded 
   - (and classloader(s) for each jar ?)
+
+- exception events analisys: grouped by type, location of occurence, catch location 
+
+- profiler: MethodEntryEvent & MethodExitEvent (should addClassFilter())