Java > Open Source Codes > org > sape > carbon > services > instrumentation > statistics > DefaultStatisticsInterceptor


1 /*
2  * The contents of this file are subject to the Sapient Public License
3  * Version 1.0 (the "License"); you may not use this file except in compliance
4  * with the License. You may obtain a copy of the License at
5  * http://carbon.sf.net/License.html.
6  *
7  * Software distributed under the License is distributed on an "AS IS" basis,
8  * WITHOUT WARRANTY OF ANY KIND, either express or implied. See the License for
9  * the specific language governing rights and limitations under the License.
10  *
11  * The Original Code is The Carbon Component Framework.
12  *
13  * The Initial Developer of the Original Code is Sapient Corporation
14  *
15  * Copyright (C) 2003 Sapient Corporation. All Rights Reserved.
16  */
17
18 package org.sape.carbon.services.instrumentation.statistics;
19
20 import org.apache.commons.logging.Log;
21 import org.apache.commons.logging.LogFactory;
22
23 import java.io.Serializable ;
24 import java.lang.reflect.Method ;
25 import java.util.ArrayList ;
26 import java.util.Collection ;
27 import java.util.Collections ;
28 import java.util.HashMap ;
29 import java.util.HashSet ;
30 import java.util.Iterator ;
31 import java.util.List ;
32 import java.util.Map ;
33
34 import org.sape.carbon.core.component.Component;
35 import org.sape.carbon.core.component.FunctionalInterface;
36 import org.sape.carbon.core.component.proxy.Interceptor;
37 import org.sape.carbon.core.component.proxy.Invocation;
38 import org.sape.carbon.core.util.reflection.ClassTree;
39 import org.sape.carbon.core.util.reflection.ClassTree.ClassTreeNode;
40
41 /**
42  * <P>This Component Interceptor can be utilized to track the execution of
43  * Carbon components. It can be configured in a component template as shown
44  * here:</P>
45  *
46  * <PRE>
47  * &lt;!-- The statistics Assistant --&gt;
48  * &lt;DecoratorConfiguration&gt;
49  * &lt;Factory&gt;org.sape.carbon.services.component.assistants.StatisticsInterceptorFactory&lt;/Factory&gt;
50  * &lt;/DecoratorConfiguration&gt;
51  * </PRE>
52  *
53  * <p>
54  * WARNING: This does not guarantee accurate statistics... it simply keeps
55  * there from being innacurrate information in each MethodStat object and
56  * from threads stepping on eachother while writing. When reading, it is
57  * possible to read some of the data inconsistently. This is accepted
58  * as this is designed to be "pretty" accurate, with little to no
59  * contention on basic method calls, and only.
60  * </p>
61  *
62  * Copyright 2002 Sapient
63  * @since carbon 1.0
64  * @author Greg Hinkle, January 2002
65  * @version $Revision: 1.11 $($Author: ghinkl $ / $Date: 2003/10/09 19:33:08 $)
66  */
67 public class DefaultStatisticsInterceptor
68     implements StatisticsInterceptor, Interceptor {
69
70     /** The handle to Apache-commons logger */
71     private Log log =
72         LogFactory.getLog(this.getClass());
73
74     /**
75      * The map of component methods to Lists of MethodStat objects. Each method
76      * has an associated list of MethodStats objects (one for each thread that
77      * has used the component). Each thread also stores a reference to this object
78      * in ThreadLocal. Only one thread will ever update a specific MethodStats
79      * object, whereas any method may read them here to aggregate the stats
80      * information.
81      *
82      * WARNING: This does not guarantee accurate statistics... it simply keeps
83      * there from being innacurrate information in each MethodStat object and
84      * from threads stepping on eachother while writing. When reading, it is
85      * possible to read some of the data inconsistently. This is accepted
86      * as this is designed to be "pretty" accurate, with little to no
87      * contention on basic method calls, and only.
88      */
89     private Map methodStats = Collections.synchronizedMap(new HashMap ());
90
91     /**
92      * This threadlocal will hold a local map of methods to MethodStats
93      * objects, allowing each thread to accurately accumulate statistics
94      * information with no locking or contention.
95      */
96     private ThreadLocal localMethodStats = new ThreadLocal () {
97         protected Object initialValue() {
98             return new HashMap ();
99         }
100     };
101
102     /**
103      * The general start time of the component
104      */
105     private long componentStartTime = System.currentTimeMillis();
106
107     /**
108      * The time at which statistics tracking began. This is either when the
109      * component was started, or the last time resetStatistics was called.
110      */
111     private long statisticsStartTime = System.currentTimeMillis();
112
113     /**
114      * The reference to the component object
115      */
116     private Component componentReference;
117
118     /**
119      * The reference to the implementation object of the component
120      */
121     private FunctionalInterface functionalImplementation;
122
123     /**
124      * The reference to the next interceptor in the chain
125      */
126     protected Interceptor nextInterceptor;
127
128     /**
129      * This object should not be insantiated manually, but only by the
130      * Component construction subsystem.
131      */
132     private DefaultStatisticsInterceptor() { }
133
134
135     /**
136      * The constructor used by the component interceptor factory
137      * to build this interceptor.
138      * @param functionalImplementation a reference to the implementation
139      * object behind
140      * the component.
141      */
142     public DefaultStatisticsInterceptor(
143             FunctionalInterface functionalImplementation) {
144
145         this.functionalImplementation = functionalImplementation;
146     }
147
148     /**
149      * Returns the start time of this component
150      * @return the start time, in milleseconds, of the component
151      */
152     public long getStartTime() {
153         return this.componentStartTime;
154     }
155
156     /**
157      * The start date of the assisted component.
158      * @return the date object of when the assisted component
159      * was started
160      */
161     public java.util.Date getStartDate() {
162         return new java.util.Date (getStartTime());
163     }
164
165     /**
166      * The count of calls to the component.
167      * @return the number of times any method on the assisted
168      * component were called.
169      */
170     public long getCallCounts() {
171         long totalCalls = 0L;
172
173         synchronized (this.methodStats) {
174             for (Iterator methodIterator = this.methodStats.entrySet().iterator(); methodIterator.hasNext();) {
175                 Map.Entry entry = (Map.Entry ) methodIterator.next();
176                 List methodList = (List ) entry.getValue();
177
178                 for (int i = 0; i < methodList.size(); i++) {
179                     MethodStats methodStats = (MethodStats) methodList.get(i);
180                     totalCalls += methodStats.getCallCount();
181                 }
182             }
183         }
184         return totalCalls;
185     }
186
187     /**
188      * A collection of the MethodStats for each method in the instrumented component.
189      * This method works by aggregating the statistics information for each
190      * thread. See the warning above about its accuracy.
191      * @return an unmodifiable collection of method MethodStats objects.
192      * @see org.sape.carbon.services.instrumentation.statistics.DefaultStatisticsInterceptor
193      */
194     public synchronized Collection getMethodStats() {
195         Collection methodStatCollection = new HashSet ();
196         synchronized (this.methodStats) {
197             for (Iterator methodIterator = this.methodStats.entrySet().iterator(); methodIterator.hasNext();) {
198                 Map.Entry entry = (Map.Entry ) methodIterator.next();
199                 Method method = (Method ) entry.getKey();
200                 List methodList = (List ) entry.getValue();
201
202                 MethodStats masterStats = new MethodStats(method);
203                 for (int i = 0; i < methodList.size(); i++) {
204                     MethodStats methodStats = (MethodStats) methodList.get(i);
205                     masterStats.setCallCount(masterStats.getCallCount() + methodStats.getCallCount());
206                     masterStats.setFailures(masterStats.getFailures() + methodStats.getFailures());
207                     masterStats.setTotalExecutionDuration(masterStats.getTotalExecutionDuration() + methodStats.getTotalExecutionDuration());
208                 }
209                 methodStatCollection.add(masterStats);
210             }
211         }
212         return methodStatCollection;
213     }
214
215     /**
216      * Logs the statistics for the tracked component to the default
217      * logging component.
218      */
219     public void logStats() {
220         StringBuffer buf = new StringBuffer ();
221         buf.append("Statistics for component[");
222         buf.append(this.functionalImplementation.getClass().getName());
223         buf.append("]:");
224
225         Collection methodStats = getMethodStats();
226         Iterator methodStatsIterator = methodStats.iterator();
227         while (methodStatsIterator.hasNext()) {
228             MethodStats methodStat = (MethodStats) methodStatsIterator.next();
229             buf.append("Method [");
230             buf.append(methodStat.getMethod().getName());
231             buf.append("] - ");
232             buf.append(methodStats.toString());
233         }
234         log.info(buf.toString());
235     }
236
237     /**
238      * This method sets the next interceptor as the next in the chain from the
239      * current interceptor.
240      * @param interceptor the next interceptor in the chain
241      */
242     public void setNextInterceptor(Interceptor interceptor) {
243         this.nextInterceptor = interceptor;
244     }
245
246     /**
247      * This should return the list of interfaces that a decorator wishes to
248      * expose through the component proxy. This is used by the
249      * component factory to determine what interfaces the component proxy will
250      * implement.
251      *
252      * @return Class[] an array of interfaces
253      */
254     public Class [] getExposedInterfaces() {
255         return new Class [] {StatisticsInterceptor.class};
256     }
257
258     /**
259      * This method must implement the invocation of any necessary actions and
260      * the chaining the next interceptor.
261      *
262      * @param invocation the invocation to execute
263      * @return the results of the invocation's execution
264      *
265      * @throws Throwable indicates an error in the interceptor chain
266      */
267     public Object invoke(Invocation invocation) throws Throwable {
268
269         boolean trackable = invocation.isTargetFunctionalImplementation();
270
271         MethodStats stats = null;
272
273
274         if (trackable) {
275
276             Map localMap = (Map ) this.localMethodStats.get();
277
278             Method method = invocation.getMethod();
279             stats = (MethodStats) localMap.get(method);
280             if (stats == null) {
281                 synchronized(this) {
282                     stats = new MethodStats(method);
283                     localMap.put(method, stats);
284                     List methodList = (List ) methodStats.get(method);
285                     if (methodList == null) {
286                         methodList = new ArrayList ();
287                         this.methodStats.put(method,methodList);
288                     }
289                     methodList.add(stats);
290                 }
291             }
292             stats.startMethodCall(System.currentTimeMillis());
293         }
294
295         try {
296
297             Object result = this.nextInterceptor.invoke(invocation);
298             if (trackable) {
299                 stats.endMethodCall(System.currentTimeMillis());
300             }
301             return result;
302         } catch (Throwable t) {
303
304             if (trackable) {
305                 stats.fail();
306             }
307             // Rethrow the failure to be handled
308 throw t;
309         }
310     }
311
312     /**
313      * @see Interceptor#setComponentReference(org.sape.carbon.core.component.Component)
314      * @inherit
315      */
316     public void setComponentReference(Component component) {
317         this.componentReference = component;
318     }
319
320     /**
321      * <p>Builds an HTML report of information about the assisted
322      * component. This report contains general information about
323      * the component as well as statistics on the total method
324      * calls and information about each method of the component.</p>
325      *
326      * <p><B>Note: </B>It should be noted that the failure counts
327      * are only updated apon the next call to a method that has
328      * failed. If a component is failing, there well may be uncounted
329      * failures, up to a count of the total threads that have had
330      * failures on the component.</p>
331      * @return an html report of information about the tracked component
332      */
333     public String getStatsReport() {
334
335         long statsTrackingTime =
336             System.currentTimeMillis() - this.statisticsStartTime;
337
338         StringBuffer buf = new StringBuffer (256);
339         buf.append("<html><body><h2>Instrumentation Report</h2>\n");
340         buf.append("<b>Component: </b>");
341             buf.append(this.componentReference.getComponentName());
342             buf.append("<br>\n");
343
344             buf.append("&nbsp;<b>Service Type: </b>");
345             buf.append(this.functionalImplementation.getClass().getName());
346             buf.append("<br>\n");
347
348             buf.append("&nbsp;<b>Started: </b>");
349             buf.append(getStartDate().toString());
350             buf.append("<br>\n");
351
352             buf.append("&nbsp;<b>Calls: </b>");
353             buf.append(getCallCounts());
354             buf.append("<p>\n");
355
356
357         buf.append("<b>Methods:</b><br>");
358         buf.append("<table border='2'><tr> <td><b>Name</b></td> ");
359         buf.append("<td><b>Calls</b></td> <td><b>Total Duration</b></td> ");
360         buf.append("<td><b>Average Duration</b></td> ");
361         buf.append("<td><b>Failures</b></td> </tr>\n");
362         Collection methodStats = getMethodStats();
363         Iterator methodStatsIterator = methodStats.iterator();
364         while (methodStatsIterator.hasNext()) {
365             MethodStats methodStat = (MethodStats) methodStatsIterator.next();
366
367             buf.append("<tr> <td>");
368             buf.append(methodStat.getMethod().getName());
369             buf.append("</td> <td>");
370             buf.append(methodStat.getCallCount());
371             buf.append("</td> <td>");
372             buf.append(methodStat.getTotalExecutionDuration());
373             buf.append("</td> <td>");
374             buf.append(
375                 ((double) methodStat.getTotalExecutionDuration())
376                 / methodStat.getCallCount());
377
378             buf.append("ms</td> <td>");
379             buf.append(methodStat.getFailures());
380             buf.append("</td> </tr>\n");
381         }
382         buf.append("</table><p>");
383
384         buf.append("<b>Generalizations:</b><br>");
385         ClassTree tree = new ClassTree(this.componentReference.getClass());
386         buf.append("<pre>\n");
387         buf.append("<pre>\n");
388
389         List list = tree.getOrderedList();
390         for (int i = 0; i < list.size(); i++) {
391             Class aClass = (Class ) list.get(i);
392             buf.append("+ " + aClass.toString() + "\n");
393         }
394
395         buf.append("</body></html>");
396
397         return buf.toString();
398     }
399
400     /**
401      * Recursively appends class information to the buffer for the given
402      * node and all child nodes.
403      *
404      * @param buf the buffer to append to
405      * @param node the node to append
406      * @param depth the depth of recursion of the child nodes.
407      */
408     private void appendClassInfo(StringBuffer buf, ClassTreeNode node,
409             int depth) {
410
411         for (int i = 0; i < depth; i++) {
412             buf.append(" ");
413         }
414         buf.append("+ ");
415         buf.append(node.getObjectClass());
416         buf.append("\n");
417         for (Iterator iterator = node.getChildren().iterator();
418              iterator.hasNext();) {
419
420             ClassTreeNode child = (ClassTreeNode) iterator.next();
421             appendClassInfo(buf, child, depth + 1);
422         }
423     }
424
425     /**
426      * Resets the statistics being tracked on the component to zero.
427      */
428     public void resetStats() {
429         synchronized (this.methodStats) {
430             this.methodStats.clear();
431         }
432         this.statisticsStartTime = 0L;
433     }
434
435     /**
436      * <p>This inner class is used to track information about an
437      * individual method on a specific component. It is thread-safe
438      * by using thread-local to track the status of individual
439      * method calls from a single thread.</p>
440      *
441      * <p>The two main methods are the start and stop method
442      * methods that begin and end the timing and tracking of the
443      * component method call. Failures, for a specific thread, are
444      * only detected apon the next call to the same method
445      * (within the same thread). This is the only way to track
446      * failures as the component system does not notify post listeners
447      * when there is a component failure.</p>
448      */
449     public static class MethodStats implements Serializable {
450         /** Holds the method being instremented. */
451         private Method method;
452
453         /** Holds the number of times the method has been called. */
454         private long callCount = 0;
455
456         /** Holds the number of times the method has failed. */
457         private long failures = 0;
458
459         /** Holds the total execution duration for the method. */
460         private long totalExecutionDuration = 0;
461
462         /**
463          * This thread local storage stores the start time of a method call
464          * in order to know when the call began. If the time is greater than
465          * zero it is considered to be executing (or to have failed).
466          * Reentrancy would cause a false positive of failure at this point.
467          */
468         private final ThreadLocal methodCall = new ThreadLocal () {
469              protected synchronized Object initialValue() {
470                  return new Long (-1L);
471              }
472          };
473
474
475          /**
476           * Creates a new thread-safe method statistics tracking object.
477           * @param method The method object of the method being tracked
478           */
479         public MethodStats(Method method) {
480             this.method = method;
481         }
482
483         /**
484          * Begins the method call tracking by placing the start time
485          * in a thread-local storage location. Also increments the
486          * call count and detects previous failures of the method by
487          * noticing the failure to call a matching "endMethodCall".
488          * @param time the time in milleseconds that the method call began
489          */
490         public void startMethodCall(final long time) {
491             this.callCount++;
492
493             // if the method was already started (for this thread) we've
494 // had a failure
495 if ((this.methodCall.get() == null)
496                     || ((Long ) this.methodCall.get()).longValue() < 0L) {
497
498                 this.methodCall.set(new Long (time));
499             } else {
500                 this.failures++;
501             }
502         }
503
504         /**
505          * Ends a call for the case of where the invocation failed.
506          */
507         public void fail() {
508             this.failures++;
509             this.methodCall.set(new Long (-1L));
510         }
511
512         /** Ends the call tracking to the method, calculating the duration
513          * and reseting the thread-local storage for the next round of
514          * tracking.
515          * @param time the time in milleseconds that the method call ended
516          */
517         public void endMethodCall(long time) {
518             long duration = time - ((Long ) this.methodCall.get()).longValue();
519             this.totalExecutionDuration += duration;
520             this.methodCall.set(new Long (-1L));
521         }
522
523         /**
524          * Returns the tracked method.
525          * @return the method object for the tracked method
526          */
527         public Method getMethod() {
528             return this.method;
529         }
530
531         /**
532          * Gets the number of times the current method was called.
533          * @return the count of calls to the tracked method
534          */
535         public long getCallCount() {
536             return this.callCount;
537         }
538
539         /**
540          * Gets the count of failures (exceptions thrown from) the
541          * component method being tracked.
542          * @return The count of failures for the tracked method.
543          */
544         public long getFailures() {
545             return this.failures;
546         }
547
548         /**
549          * Gets the total time in milleseconds spent in the tracked
550          * component. <b>Note:</b> Does not track the duration of time
551          * spent in method calls that fail. Only succesful calls can be
552          * counted.
553          * @return the time in milleseconds spent executing the tracked
554          * method.
555          */
556         public long getTotalExecutionDuration() {
557             return this.totalExecutionDuration;
558         }
559
560         protected void setCallCount(long callCount) {
561             this.callCount = callCount;
562         }
563
564         protected void setFailures(long failures) {
565             this.failures = failures;
566         }
567
568         protected void setTotalExecutionDuration(long totalExecutionDuration) {
569             this.totalExecutionDuration = totalExecutionDuration;
570         }
571
572         /**
573          * Converts the object into a simple String representation.
574          *
575          * @return a simple String representation
576          */
577         public String toString() {
578             StringBuffer buffer = new StringBuffer ();
579
580             buffer.append("Method Statistics(");
581             buffer.append(this.method.getName());
582             buffer.append(") Calls: ");
583             buffer.append(getCallCount());
584             buffer.append(" Duration: ");
585             buffer.append(this.getTotalExecutionDuration());
586             buffer.append(" Failures: ");
587             buffer.append(this.getFailures());
588
589             return buffer.toString();
590         }
591
592     }
593 }
594

A to Z: JavaDoc & Examples

---

Daily Java News & Articles

---

Open Source Projects

---

Open Source Codes

---

Free Computer Books

---

Remove Frame

---

Popular Tags