001/*
002 * Licensed to the Apache Software Foundation (ASF) under one or more
003 * contributor license agreements. See the NOTICE file distributed with
004 * this work for additional information regarding copyright ownership.
005 * The ASF licenses this file to You under the Apache license, Version 2.0
006 * (the "License"); you may not use this file except in compliance with
007 * the License. You may obtain a copy of the License at
008 *
009 *      http://www.apache.org/licenses/LICENSE-2.0
010 *
011 * Unless required by applicable law or agreed to in writing, software
012 * distributed under the License is distributed on an "AS IS" BASIS,
013 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
014 * See the license for the specific language governing permissions and
015 * limitations under the license.
016 */
017package org.apache.logging.log4j.util;
018
019import java.io.Serializable;
020import java.text.DecimalFormat;
021
022/**
023 * Primarily used in unit tests, but can be used to track elapsed time for a request or portion of any other operation
024 * so long as all the timer methods are called on the same thread in which it was started. Calling start on
025 * multiple threads will cause the times to be aggregated.
026 */
027public class Timer implements Serializable, StringBuilderFormattable
028{
029    private static final long serialVersionUID = 9175191792439630013L;
030
031    private final String name;        // The timer's name
032    public enum Status {
033        Started, Stopped, Paused
034    }
035    private Status status; // The timer's status
036    private long elapsedTime;         // The elapsed time
037    private final int iterations;
038    private static long NANO_PER_SECOND = 1000000000L;
039    private static long NANO_PER_MINUTE = NANO_PER_SECOND * 60;
040    private static long NANO_PER_HOUR = NANO_PER_MINUTE * 60;
041    private ThreadLocal<Long> startTime = new ThreadLocal<Long>() {
042            @Override protected Long initialValue() {
043                return 0L;
044            }
045    };
046
047
048    /**
049     * Constructor.
050     * @param name the timer name.
051     */
052    public Timer(final String name)
053    {
054        this(name, 0);
055    }
056
057    /**
058     * Constructor.
059     *
060     * @param name the timer name.
061     */
062    public Timer(final String name, final int iterations)
063    {
064        this.name = name;
065        status = Status.Stopped;
066        this.iterations = (iterations > 0) ? iterations : 0;
067    }
068
069    /**
070     * Start the timer.
071     */
072    public synchronized void start()
073    {
074        startTime.set(System.nanoTime());
075        elapsedTime = 0;
076        status = Status.Started;
077    }
078
079    public synchronized void startOrResume() {
080        if (status == Status.Stopped) {
081            start();
082        } else {
083            resume();
084        }
085    }
086
087    /**
088     * Stop the timer.
089     */
090    public synchronized String stop()
091    {
092        elapsedTime += System.nanoTime() - startTime.get();
093        startTime.set(0L);
094        status = Status.Stopped;
095        return toString();
096    }
097
098    /**
099     * 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}