View Javadoc
1   /*
2    * Licensed to the Apache Software Foundation (ASF) under one or more
3    * contributor license agreements. See the NOTICE file distributed with
4    * this work for additional information regarding copyright ownership.
5    * The ASF licenses this file to You under the Apache license, Version 2.0
6    * (the "License"); you may not use this file except in compliance with
7    * the License. You may obtain a copy of the License at
8    *
9    *      http://www.apache.org/licenses/LICENSE-2.0
10   *
11   * Unless required by applicable law or agreed to in writing, software
12   * distributed under the License is distributed on an "AS IS" BASIS,
13   * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
14   * See the license for the specific language governing permissions and
15   * limitations under the license.
16   */
17  package org.apache.logging.log4j.util;
18  
19  import java.io.Serializable;
20  import java.text.DecimalFormat;
21  
22  /**
23   * Primarily used in unit tests, but can be used to track elapsed time for a request or portion of any other operation
24   * so long as all the timer methods are called on the same thread in which it was started. Calling start on
25   * multiple threads will cause the the times to be aggregated.
26   */
27  public class Timer implements Serializable, StringBuilderFormattable
28  {
29      private static final long serialVersionUID = 9175191792439630013L;
30  
31      private final String name;        // The timer's name
32      public enum Status {
33          Started, Stopped, Paused
34      }
35      private Status status; // The timer's status
36      private long elapsedTime;         // The elapsed time
37      private final int iterations;
38      private static long NANO_PER_SECOND = 1000000000L;
39      private static long NANO_PER_MINUTE = NANO_PER_SECOND * 60;
40      private static long NANO_PER_HOUR = NANO_PER_MINUTE * 60;
41      private ThreadLocal<Long> startTime = new ThreadLocal<Long>() {
42              @Override protected Long initialValue() {
43                  return 0L;
44              }
45      };
46  
47  
48      /**
49       * Constructor.
50       * @param name the timer name.
51       */
52      public Timer(final String name)
53      {
54          this(name, 0);
55      }
56  
57      /**
58       * Constructor.
59       *
60       * @param name the timer name.
61       */
62      public Timer(final String name, final int iterations)
63      {
64          this.name = name;
65          status = Status.Stopped;
66          this.iterations = (iterations > 0) ? iterations : 0;
67      }
68  
69      /**
70       * Start the timer.
71       */
72      public synchronized void start()
73      {
74          startTime.set(System.nanoTime());
75          elapsedTime = 0;
76          status = Status.Started;
77      }
78  
79      public synchronized void startOrResume() {
80          if (status == Status.Stopped) {
81              start();
82          } else {
83              resume();
84          }
85      }
86  
87      /**
88       * Stop the timer.
89       */
90      public synchronized String stop()
91      {
92          elapsedTime += System.nanoTime() - startTime.get();
93          startTime.set(0L);
94          status = Status.Stopped;
95          return toString();
96      }
97  
98      /**
99       * Pause the timer.
100      */
101     public synchronized void pause()
102     {
103         elapsedTime += System.nanoTime() - startTime.get();
104         startTime.set(0L);
105         status = Status.Paused;
106     }
107 
108     /**
109      * Resume the timer.
110      */
111     public synchronized void resume()
112     {
113         startTime.set(System.nanoTime());
114         status = Status.Started;
115     }
116 
117     /**
118      * Accessor for the name.
119      * @return the timer's name.
120      */
121     public String getName()
122     {
123         return name;
124     }
125 
126     /**
127      * Access the elapsed time.
128      *
129      * @return the elapsed time.
130      */
131     public long getElapsedTime()
132     {
133         return elapsedTime / 1000000;
134     }
135 
136     /**
137      * Access the elapsed time.
138      *
139      * @return the elapsed time.
140      */
141     public long getElapsedNanoTime()
142     {
143         return elapsedTime;
144     }
145 
146     /**
147      * Returns the name of the last operation performed on this timer (Start, Stop, Pause or
148      * Resume).
149      * @return the string representing the last operation performed.
150      */
151     public Status getStatus()
152     {
153         return status;
154     }
155 
156     /**
157      * Returns the String representation of the timer based upon its current state
158      */
159     @Override
160     public String toString()
161     {
162         final StringBuilder result = new StringBuilder();
163         formatTo(result);
164         return result.toString();
165     }
166 
167     @Override
168     public void formatTo(final StringBuilder buffer) {
169         buffer.append("Timer ").append(name);
170         switch (status) {
171             case Started:
172                 buffer.append(" started");
173                 break;
174             case Paused:
175                 buffer.append(" paused");
176                 break;
177             case Stopped:
178                 long nanoseconds = elapsedTime;
179                 // Get elapsed hours
180                 long hours = nanoseconds / NANO_PER_HOUR;
181                 // Get remaining nanoseconds
182                 nanoseconds = nanoseconds % NANO_PER_HOUR;
183                 // Get minutes
184                 long minutes = nanoseconds / NANO_PER_MINUTE;
185                 // Get remaining nanoseconds
186                 nanoseconds = nanoseconds % NANO_PER_MINUTE;
187                 // Get seconds
188                 long seconds = nanoseconds / NANO_PER_SECOND;
189                 // Get remaining nanoseconds
190                 nanoseconds = nanoseconds % NANO_PER_SECOND;
191 
192                 String elapsed = Strings.EMPTY;
193 
194                 if (hours > 0) {
195                     elapsed += hours + " hours ";
196                 }
197                 if (minutes > 0 || hours > 0) {
198                     elapsed += minutes + " minutes ";
199                 }
200 
201                 DecimalFormat numFormat;
202                 numFormat = new DecimalFormat("#0");
203                 elapsed += numFormat.format(seconds) + '.';
204                 numFormat = new DecimalFormat("000000000");
205                 elapsed += numFormat.format(nanoseconds) + " seconds";
206                 buffer.append(" stopped. Elapsed time: ").append(elapsed);
207                 if (iterations > 0) {
208                     nanoseconds = elapsedTime / iterations;
209                     // Get elapsed hours
210                     hours = nanoseconds / NANO_PER_HOUR;
211                     // Get remaining nanoseconds
212                     nanoseconds = nanoseconds % NANO_PER_HOUR;
213                     // Get minutes
214                     minutes = nanoseconds / NANO_PER_MINUTE;
215                     // Get remaining nanoseconds
216                     nanoseconds = nanoseconds % NANO_PER_MINUTE;
217                     // Get seconds
218                     seconds = nanoseconds / NANO_PER_SECOND;
219                     // Get remaining nanoseconds
220                     nanoseconds = nanoseconds % NANO_PER_SECOND;
221 
222                     elapsed = Strings.EMPTY;
223 
224                     if (hours > 0) {
225                         elapsed += hours + " hours ";
226                     }
227                     if (minutes > 0 || hours > 0) {
228                         elapsed += minutes + " minutes ";
229                     }
230 
231                     numFormat = new DecimalFormat("#0");
232                     elapsed += numFormat.format(seconds) + '.';
233                     numFormat = new DecimalFormat("000000000");
234                     elapsed += numFormat.format(nanoseconds) + " seconds";
235                     buffer.append(" Average per iteration: ").append(elapsed);
236                 }
237                 break;
238             default:
239                 buffer.append(' ').append(status);
240                 break;
241         }
242     }
243 
244     @Override
245     public boolean equals(final Object o) {
246         if (this == o) {
247             return true;
248         }
249         if (!(o instanceof Timer)) {
250             return false;
251         }
252 
253         final Timer timer = (Timer) o;
254 
255         if (elapsedTime != timer.elapsedTime) {
256             return false;
257         }
258         if (startTime != timer.startTime) {
259             return false;
260         }
261         if (name != null ? !name.equals(timer.name) : timer.name != null) {
262             return false;
263         }
264         if (status != null ? !status.equals(timer.status) : timer.status != null) {
265             return false;
266         }
267 
268         return true;
269     }
270 
271     @Override
272     public int hashCode() {
273         int result;
274         result = (name != null ? name.hashCode() : 0);
275         result = 29 * result + (status != null ? status.hashCode() : 0);
276         long time = startTime.get();
277         result = 29 * result + (int) (time ^ (time >>> 32));
278         result = 29 * result + (int) (elapsedTime ^ (elapsedTime >>> 32));
279         return result;
280     }
281 
282 }