This project has retired. For details please refer to its Attic page.
TimeLogger xref

1   /*
2    * Licensed to the Apache Software Foundation (ASF) under one
3    * or more contributor license agreements.  See the NOTICE file
4    * distributed with this work for additional information
5    * regarding copyright ownership.  The ASF licenses this file
6    * to you under the Apache License, Version 2.0 (the
7    * "License"); you may not use this file except in compliance
8    * with the License.  You may obtain a copy of the License at
9    *
10   * http://www.apache.org/licenses/LICENSE-2.0
11   *
12   * Unless required by applicable law or agreed to in writing,
13   * software distributed under the License is distributed on an
14   * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
15   * KIND, either express or implied.  See the License for the
16   * specific language governing permissions and limitations
17   * under the License.
18   */
19  package org.apache.chemistry.opencmis.util.repository;
20  
21  import java.util.LinkedList;
22  
23  import org.apache.commons.logging.Log;
24  import org.apache.commons.logging.LogFactory;
25  
26  /**
27   * Simple utility class for time logging Note: NOT thread safe!
28   *
29   * @author Jens
30   *
31   */
32  public class TimeLogger {
33      private static final Log LOG = LogFactory.getLog(TimeLogger.class);
34  
35      private static class TimeRecord {
36          public long fStart;
37          public long fStop;
38      }
39  
40      private final String fAction;
41      private LinkedList<TimeRecord> fTimeRecs = new LinkedList<TimeRecord>();
42      private final int maxSize = 2500;
43      TimeRecord fCurrentRec;
44  
45      public TimeLogger() {
46          fAction = "";
47          fTimeRecs = new LinkedList<TimeRecord>();
48      }
49  
50      public TimeLogger(String action) {
51          fAction = action;
52      }
53  
54      public void start() {
55          createAndAddNewRecord();
56          fCurrentRec.fStart = System.currentTimeMillis();
57      }
58  
59      public void stop() {
60          fCurrentRec.fStop = System.currentTimeMillis();
61      }
62  
63      public void reset() {
64          fTimeRecs.clear();
65      }
66  
67      public void logTimes() {
68          long size = fTimeRecs.size();
69          if (size == 0) {
70              LOG.info("No samples for " + fAction + " available. ");
71          } else if (size == 1) {
72              LOG.info("Time elapsed for " + fAction + ": " + getLastTime());
73          } else {
74              LOG.info("Timings for " + size + " samples for action " + fAction + ": ");
75              LOG.info("  Average: " + getAverageTime() + "ms");
76              LOG.info("  Min    : " + getMinTime() + "ms");
77              LOG.info("  Max    : " + getMaxTime() + "ms");
78              LOG.info("  Total  : " + getTotalTime() + "ms");
79          }
80      }
81  
82      public void printTimes() {
83          long size = fTimeRecs.size();
84          if (size == 0) {
85              System.out.println("No samples for " + fAction + " available. ");
86          } else if (size == 1) {
87              System.out.println("Time elapsed for " + fAction + ": " + getLastTime());
88          } else {
89              System.out.println("Timings for " + size + " samples for action " + fAction + ": ");
90              System.out.println("  Average: " + getAverageTime() + "ms");
91              System.out.println("  Min    : " + getMinTime() + "ms");
92              System.out.println("  Max    : " + getMaxTime() + "ms");
93              System.out.println("  Total  : " + getTotalTime() + "ms");
94          }
95      }
96  
97      public long getLastTime() {
98          TimeRecord lastRec = fTimeRecs.getLast();
99          if (null != lastRec) {
100             return lastRec.fStop - lastRec.fStart;
101         } else {
102             return 0;
103         }
104     }
105 
106     private void createAndAddNewRecord() {
107         if (fTimeRecs.size() < maxSize) {
108             fCurrentRec = new TimeRecord();
109             fTimeRecs.add(fCurrentRec);
110         }
111     }
112 
113     private long getAverageTime() {
114         long sum = 0;
115         long size = fTimeRecs.size();
116 
117         if (0 == fTimeRecs.size()) {
118             return 0;
119         }
120 
121         for (TimeRecord tm : fTimeRecs) {
122             sum += tm.fStop - tm.fStart;
123         }
124         return (sum + size / 2) / size;
125     }
126 
127     private long getMinTime() {
128         long min = Long.MAX_VALUE;
129 
130         if (0 == fTimeRecs.size()) {
131             return 0;
132         }
133 
134         for (TimeRecord tm : fTimeRecs) {
135             long val = tm.fStop - tm.fStart;
136             if (val < min) {
137                 min = val;
138             }
139         }
140         return min;
141 
142     }
143 
144     private long getMaxTime() {
145         long max = Long.MIN_VALUE;
146 
147         if (0 == fTimeRecs.size()) {
148             return 0;
149         }
150 
151         for (TimeRecord tm : fTimeRecs) {
152             long val = tm.fStop - tm.fStart;
153             if (val > max) {
154                 max = val;
155             }
156         }
157         return max;
158     }
159 
160     private long getTotalTime() {
161         long sum = 0;
162 
163         for (TimeRecord tm : fTimeRecs) {
164             sum += tm.fStop - tm.fStart;
165         }
166         return sum;
167     }
168 
169     // //////////////////////////////////////////////////////////////////////////
170     // ////////
171     //
172     // Same methods used for multithreaded logging
173 
174     public static void logTimes(TimeLogger[] loggers) {
175         long size = 0;
176         if (null == loggers) {
177             return;
178         }
179 
180         for (int i = 0; i < loggers.length; i++) {
181             size += loggers[i].fTimeRecs.size();
182         }
183 
184         LOG.info("Timings for " + size + " samples for action " + loggers[0].fAction + ": ");
185         LOG.info("  Average: " + getAverageTime(loggers) + "ms");
186         LOG.info("  Min    : " + getMinTime(loggers) + "ms");
187         LOG.info("  Max    : " + getMaxTime(loggers) + "ms");
188         LOG.info("  Total  : " + getTotalTime(loggers) + "ms");
189     }
190 
191     public static void printTimes(TimeLogger[] loggers) {
192         long size = 0;
193         if (null == loggers) {
194             return;
195         }
196 
197         for (int i = 0; i < loggers.length; i++) {
198             size += loggers[i].fTimeRecs.size();
199         }
200 
201         System.out.println("Timings for " + size + " samples for action " + loggers[0].fAction + ": ");
202         System.out.println("  Average: " + getAverageTime(loggers) + "ms");
203         System.out.println("  Min    : " + getMinTime(loggers) + "ms");
204         System.out.println("  Max    : " + getMaxTime(loggers) + "ms");
205         System.out.println("  Total  : " + getTotalTime(loggers) + "ms");
206 
207     }
208 
209     private static long getAverageTime(TimeLogger[] loggers) {
210         long sum = 0;
211         long size = 0;
212 
213         for (int i = 0; i < loggers.length; i++) {
214             size += loggers[i].fTimeRecs.size();
215         }
216 
217         if (size == 0) {
218             return 0;
219         }
220 
221         for (int i = 0; i < loggers.length; i++) {
222             if (0 == loggers[i].fTimeRecs.size()) {
223                 continue;
224             }
225 
226             for (TimeRecord tm : loggers[i].fTimeRecs) {
227                 sum += tm.fStop - tm.fStart;
228             }
229         }
230 
231         return (sum + size / 2) / size;
232     }
233 
234     private static long getMaxTime(TimeLogger[] loggers) {
235         long max = Long.MIN_VALUE;
236 
237         for (int i = 0; i < loggers.length; i++) {
238             long val = loggers[i].getMaxTime();
239             if (val > max) {
240                 max = val;
241             }
242         }
243 
244         return max;
245     }
246 
247     private static long getMinTime(TimeLogger[] loggers) {
248         long min = Long.MAX_VALUE;
249 
250         for (int i = 0; i < loggers.length; i++) {
251             long val = loggers[i].getMinTime();
252             if (val < min) {
253                 min = val;
254             }
255         }
256 
257         return min;
258     }
259 
260     private static long getTotalTime(TimeLogger[] loggers) {
261         long totalTime = Long.MIN_VALUE;
262 
263         for (int i = 0; i < loggers.length; i++) {
264             long val = loggers[i].getTotalTime();
265             if (val > totalTime) {
266                 totalTime = val;
267             }
268         }
269 
270         return totalTime;
271     }
272 
273 }