1 /*
2 * Copyright (c) 1997, 2016, Oracle and/or its affiliates. All rights reserved.
3 * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
4 *
5 * This code is free software; you can redistribute it and/or modify it
6 * under the terms of the GNU General Public License version 2 only, as
7 * published by the Free Software Foundation.
8 *
9 * This code is distributed in the hope that it will be useful, but WITHOUT
10 * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
11 * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License
12 * version 2 for more details (a copy is included in the LICENSE file that
13 * accompanied this code).
14 *
15 * You should have received a copy of the GNU General Public License version
16 * 2 along with this work; if not, write to the Free Software Foundation,
17 * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
18 *
19 * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
20 * or visit www.oracle.com if you need additional information or have any
21 * questions.
22 *
23 */
24
25 #include "precompiled.hpp"
26 #include "logging/log.hpp"
27 #include "oops/oop.inline.hpp"
28 #include "runtime/timer.hpp"
29 #include "utilities/ostream.hpp"
30
31 double TimeHelper::counter_to_seconds(jlong counter) {
32 double freq = (double) os::elapsed_frequency();
33 return counter / freq;
34 }
35
36 double TimeHelper::counter_to_millis(jlong counter) {
37 return counter_to_seconds(counter) * 1000.0;
38 }
39
40 elapsedTimer::elapsedTimer(jlong time, jlong timeUnitsPerSecond) {
41 _active = false;
42 jlong osTimeUnitsPerSecond = os::elapsed_frequency();
43 assert(osTimeUnitsPerSecond % 1000 == 0, "must be");
44 assert(timeUnitsPerSecond % 1000 == 0, "must be");
45 while (osTimeUnitsPerSecond < timeUnitsPerSecond) {
46 timeUnitsPerSecond /= 1000;
47 time *= 1000;
48 }
49 while (osTimeUnitsPerSecond > timeUnitsPerSecond) {
50 timeUnitsPerSecond *= 1000;
51 time /= 1000;
52 }
53 _counter = time;
54 }
55
56 void elapsedTimer::add(elapsedTimer t) {
57 _counter += t._counter;
58 }
59
60 void elapsedTimer::start() {
61 if (!_active) {
62 _active = true;
63 _start_counter = os::elapsed_counter();
64 }
65 }
66
67 void elapsedTimer::stop() {
68 if (_active) {
69 _counter += os::elapsed_counter() - _start_counter;
70 _active = false;
71 }
72 }
73
74 double elapsedTimer::seconds() const {
75 return TimeHelper::counter_to_seconds(_counter);
76 }
77
78 jlong elapsedTimer::milliseconds() const {
79 return (jlong)TimeHelper::counter_to_millis(_counter);
80 }
81
82 jlong elapsedTimer::active_ticks() const {
83 if (!_active) {
84 return ticks();
85 }
86 jlong counter = _counter + os::elapsed_counter() - _start_counter;
87 return counter;
88 }
89
90 void TimeStamp::update_to(jlong ticks) {
91 _counter = ticks;
92 if (_counter == 0) _counter = 1;
93 assert(is_updated(), "must not look clear");
94 }
95
96 void TimeStamp::update() {
97 update_to(os::elapsed_counter());
98 }
99
100 double TimeStamp::seconds() const {
101 assert(is_updated(), "must not be clear");
102 jlong new_count = os::elapsed_counter();
103 return TimeHelper::counter_to_seconds(new_count - _counter);
104 }
105
106 jlong TimeStamp::milliseconds() const {
107 assert(is_updated(), "must not be clear");
108 jlong new_count = os::elapsed_counter();
109 return (jlong)TimeHelper::counter_to_millis(new_count - _counter);
110 }
111
112 jlong TimeStamp::ticks_since_update() const {
113 assert(is_updated(), "must not be clear");
114 return os::elapsed_counter() - _counter;
115 }
116
117 TraceTime::TraceTime(const char* title,
118 bool doit,
119 LogTagType tag) {
120 _active = doit;
121 _verbose = true;
122 _tag = tag;
123 _title = title;
124
125 if (_active) {
126 _accum = NULL;
127 _t.start();
128 }
129 }
130
131 TraceTime::TraceTime(const char* title,
132 elapsedTimer* accumulator,
133 bool doit,
134 bool verbose,
135 LogTagType tag) {
136 _active = doit;
137 _verbose = verbose;
138 _tag = tag;
139 _title = title;
140
141 if (_active) {
142 _accum = accumulator;
143 _t.start();
144 }
145 }
146
147 TraceTime::~TraceTime() {
148 if (_active) {
149 _t.stop();
150 if (_accum!=NULL) _accum->add(_t);
151 if (_verbose) {
152 switch (_tag) {
153 case LogTag::_startuptime :
154 log_info(startuptime)("%s, %3.7f secs", _title, _t.seconds());
155 break;
156 case LogTag::__NO_TAG :
157 default :
158 tty->print_cr("[%s, %3.7f secs]", _title, _t.seconds());
159 tty->flush();
160 }
161 }
162 }
163 }
164
165 TraceCPUTime::TraceCPUTime(bool doit,
166 bool print_cr,
167 outputStream *logfile) :
168 _active(doit),
169 _print_cr(print_cr),
170 _starting_user_time(0.0),
171 _starting_system_time(0.0),
172 _starting_real_time(0.0),
173 _logfile(logfile),
174 _error(false) {
175 if (_active) {
176 if (logfile != NULL) {
177 _logfile = logfile;
178 } else {
179 _logfile = tty;
180 }
181
182 _error = !os::getTimesSecs(&_starting_real_time,
183 &_starting_user_time,
184 &_starting_system_time);
185 }
186 }
187
188 TraceCPUTime::~TraceCPUTime() {
189 if (_active) {
190 bool valid = false;
191 if (!_error) {
192 double real_secs; // walk clock time
193 double system_secs; // system time
194 double user_secs; // user time for all threads
195
196 double real_time, user_time, system_time;
197 valid = os::getTimesSecs(&real_time, &user_time, &system_time);
198 if (valid) {
199
200 user_secs = user_time - _starting_user_time;
201 system_secs = system_time - _starting_system_time;
202 real_secs = real_time - _starting_real_time;
203
204 _logfile->print(" [Times: user=%3.2f sys=%3.2f real=%3.2f secs] ",
205 user_secs, system_secs, real_secs);
206
207 } else {
208 _logfile->print("[Invalid result in TraceCPUTime]");
209 }
210 } else {
211 _logfile->print("[Error in TraceCPUTime]");
212 }
213 if (_print_cr) {
214 _logfile->cr();
215 }
216 _logfile->flush();
217 }
218 }