KickJava   Java API By Example, From Geeks To Geeks.

Java > Open Source Codes > org > alfresco > util > perf > AbstractPerformanceMonitor


1 /*
2  * Copyright (C) 2005 Alfresco, Inc.
3  *
4  * Licensed under the Mozilla Public License version 1.1
5  * with a permitted attribution clause. You may obtain a
6  * copy of the License at
7  *
8  * http://www.alfresco.org/legal/license.txt
9  *
10  * Unless required by applicable law or agreed to in writing,
11  * software distributed under the License is distributed on an
12  * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND,
13  * either express or implied. See the License for the specific
14  * language governing permissions and limitations under the
15  * License.
16  */
17 package org.alfresco.util.perf;
18
19 import java.text.DecimalFormat JavaDoc;
20 import java.util.Set JavaDoc;
21 import java.util.SortedMap JavaDoc;
22 import java.util.TreeMap JavaDoc;
23
24 import org.apache.commons.logging.Log;
25 import org.apache.commons.logging.LogFactory;
26
27 /**
28  * An instance of this class keeps track of timings of method calls made against
29  * a named entity. Logging can occur either after each recorded time, or only on
30  * VM shutdown or both.
31  * <p>
32  * Logging output is managed down to either the entity or entity-invocation level as follows:
33  * <p>
34  * <pre>
35  * performance.summary.method
36  * performance.summary.vm
37  * AND
38  * performance.targetEntityName
39  * performance.targetEntityName.methodName
40  * </pre>
41  * <p>
42  * The following examples illustrate how it can be used:
43  * <p>
44  * <pre>
45  * performance.summary.method=DEBUG
46  * performance.myBean=DEBUG
47  * --> Output method invocation statistic on each call to myBean
48  *
49  * performance.summary.vm=DEBUG
50  * performance.myBean.doSomething=DEBUG
51  * --> Output summary for doSomething() invocations on myBean when VM terminates
52  *
53  * performance=DEBUG
54  * --> Output all performance data - after each invocation and upon VM closure
55  * </pre>
56  * <p>
57  *
58  * @author Derek Hulley
59  */
60 public abstract class AbstractPerformanceMonitor
61 {
62     /** logger for method level performance summaries */
63     private static final Log methodSummaryLogger = LogFactory.getLog("performance.summary.method");
64     /** logger for VM level performance summaries */
65     private static final Log vmSummaryLogger = LogFactory.getLog("performance.summary.vm");
66     
67     private final String JavaDoc entityName;
68     /** VM level summary */
69     private SortedMap JavaDoc<String JavaDoc, MethodStats> stats;
70
71     /**
72      * Convenience method to check if there is some sort of performance logging enabled
73      *
74      * @return Returns true if there is some sort of performance logging enabled, false otherwise
75      */
76     public static boolean isDebugEnabled()
77     {
78         return (vmSummaryLogger.isDebugEnabled() || methodSummaryLogger.isDebugEnabled());
79     }
80     
81     /**
82      * @param entityName the name of the entity for which the performance is being recorded
83      */
84     public AbstractPerformanceMonitor(String JavaDoc entityName)
85     {
86         this.entityName = entityName;
87         stats = new TreeMap JavaDoc<String JavaDoc, MethodStats>();
88         
89         // enable a VM shutdown hook if required
90 if (vmSummaryLogger.isDebugEnabled())
91         {
92             Thread JavaDoc hook = new ShutdownThread();
93             Runtime.getRuntime().addShutdownHook(hook);
94         }
95     }
96     
97     /**
98      * Dumps the results of the method execution to:
99      * <ul>
100      * <li>DEBUG output if the method level debug logging is active</li>
101      * <li>Performance store if required</li>
102      * </ul>
103      *
104      * @param methodName the name of the method against which to store the results
105      * @param delayMs
106      */
107     protected void recordStats(String JavaDoc methodName, double delayMs)
108     {
109         Log methodLogger = LogFactory.getLog("performance." + entityName + "." + methodName);
110         if (!methodLogger.isDebugEnabled())
111         {
112             // no recording for this method
113 return;
114         }
115
116         DecimalFormat JavaDoc format = new DecimalFormat JavaDoc ();
117         format.setMinimumFractionDigits (3);
118         format.setMaximumFractionDigits (3);
119
120         // must we log on a per-method call?
121 if (methodSummaryLogger.isDebugEnabled())
122         {
123             methodLogger.debug("Executed " + entityName + "#" + methodName + " in " + format.format(delayMs) + "ms");
124         }
125         if (vmSummaryLogger.isDebugEnabled())
126         {
127             synchronized(this) // only synchronize if absolutely necessary
128 {
129                 // get stats
130 MethodStats methodStats = stats.get(methodName);
131                 if (methodStats == null)
132                 {
133                     methodStats = new MethodStats();
134                     stats.put(methodName, methodStats);
135                 }
136                 methodStats.record(delayMs);
137             }
138         }
139     }
140     
141     /**
142      * Stores the execution count and total execution time for any method
143      */
144     private class MethodStats
145     {
146         private int count;
147         private double totalTimeMs;
148         
149         /**
150          * Records the time for a method to execute and bumps up the execution count
151          *
152          * @param delayMs the time the method took to execute in milliseconds
153          */
154         public void record(double delayMs)
155         {
156            count++;
157            totalTimeMs += delayMs;
158         }
159         
160         public String JavaDoc toString()
161         {
162             DecimalFormat JavaDoc format = new DecimalFormat JavaDoc ();
163             format.setMinimumFractionDigits (3);
164             format.setMaximumFractionDigits (3);
165             double averageMs = totalTimeMs / (long) count;
166             return ("Executed " + count + " times, averaging " + format.format(averageMs) + "ms per call");
167         }
168     }
169     
170     /**
171      * Dumps the output of all recorded method statistics
172      */
173     private class ShutdownThread extends Thread JavaDoc
174     {
175         public void run()
176         {
177             String JavaDoc beanName = AbstractPerformanceMonitor.this.entityName;
178             
179             // prevent multiple ShutdownThread instances interleaving their output
180 synchronized(ShutdownThread.class)
181             {
182                 vmSummaryLogger.debug("\n==================== " + beanName.toUpperCase() + " ===================");
183                 Set JavaDoc<String JavaDoc> methodNames = stats.keySet();
184                 for (String JavaDoc methodName : methodNames)
185                 {
186                     vmSummaryLogger.debug("\nMethod performance summary: \n" +
187                             " Bean: " + AbstractPerformanceMonitor.this.entityName + "\n" +
188                             " Method: " + methodName + "\n" +
189                             " Statistics: " + stats.get(methodName));
190                 }
191             }
192         }
193     }
194 }
195
Popular Tags