Tue, 07 Jul 2009 14:23:00 -0400
6855834: G1: minimize the output when -XX:+PrintHeapAtGC is set
Summary: Changing the behavior of -XX:+PrintHeapAtGC for G1 from printing lengthy, per-region information to instead printing a concise summary.
Reviewed-by: ysr, apetrusenko, jcoomes
duke@435 | 1 | /* |
duke@435 | 2 | * Copyright 1997-2006 Sun Microsystems, Inc. All Rights Reserved. |
duke@435 | 3 | * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. |
duke@435 | 4 | * |
duke@435 | 5 | * This code is free software; you can redistribute it and/or modify it |
duke@435 | 6 | * under the terms of the GNU General Public License version 2 only, as |
duke@435 | 7 | * published by the Free Software Foundation. |
duke@435 | 8 | * |
duke@435 | 9 | * This code is distributed in the hope that it will be useful, but WITHOUT |
duke@435 | 10 | * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or |
duke@435 | 11 | * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License |
duke@435 | 12 | * version 2 for more details (a copy is included in the LICENSE file that |
duke@435 | 13 | * accompanied this code). |
duke@435 | 14 | * |
duke@435 | 15 | * You should have received a copy of the GNU General Public License version |
duke@435 | 16 | * 2 along with this work; if not, write to the Free Software Foundation, |
duke@435 | 17 | * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA. |
duke@435 | 18 | * |
duke@435 | 19 | * Please contact Sun Microsystems, Inc., 4150 Network Circle, Santa Clara, |
duke@435 | 20 | * CA 95054 USA or visit www.sun.com if you need additional information or |
duke@435 | 21 | * have any questions. |
duke@435 | 22 | * |
duke@435 | 23 | */ |
duke@435 | 24 | |
duke@435 | 25 | # include "incls/_precompiled.incl" |
duke@435 | 26 | # include "incls/_timer.cpp.incl" |
duke@435 | 27 | |
duke@435 | 28 | |
duke@435 | 29 | void elapsedTimer::add(elapsedTimer t) { |
duke@435 | 30 | _counter += t._counter; |
duke@435 | 31 | } |
duke@435 | 32 | |
duke@435 | 33 | void elapsedTimer::start() { |
duke@435 | 34 | if (!_active) { |
duke@435 | 35 | _active = true; |
duke@435 | 36 | _start_counter = os::elapsed_counter(); |
duke@435 | 37 | } |
duke@435 | 38 | } |
duke@435 | 39 | |
duke@435 | 40 | void elapsedTimer::stop() { |
duke@435 | 41 | if (_active) { |
duke@435 | 42 | _counter += os::elapsed_counter() - _start_counter; |
duke@435 | 43 | _active = false; |
duke@435 | 44 | } |
duke@435 | 45 | } |
duke@435 | 46 | |
duke@435 | 47 | double elapsedTimer::seconds() const { |
duke@435 | 48 | double count = (double) _counter; |
duke@435 | 49 | double freq = (double) os::elapsed_frequency(); |
duke@435 | 50 | return count/freq; |
duke@435 | 51 | } |
duke@435 | 52 | |
duke@435 | 53 | jlong elapsedTimer::milliseconds() const { |
duke@435 | 54 | jlong ticks_per_ms = os::elapsed_frequency() / 1000; |
duke@435 | 55 | return _counter / ticks_per_ms; |
duke@435 | 56 | } |
duke@435 | 57 | |
duke@435 | 58 | jlong elapsedTimer::active_ticks() const { |
duke@435 | 59 | if (!_active) { |
duke@435 | 60 | return ticks(); |
duke@435 | 61 | } |
duke@435 | 62 | jlong counter = _counter + os::elapsed_counter() - _start_counter; |
duke@435 | 63 | return counter; |
duke@435 | 64 | } |
duke@435 | 65 | |
duke@435 | 66 | void TimeStamp::update_to(jlong ticks) { |
duke@435 | 67 | _counter = ticks; |
duke@435 | 68 | if (_counter == 0) _counter = 1; |
duke@435 | 69 | assert(is_updated(), "must not look clear"); |
duke@435 | 70 | } |
duke@435 | 71 | |
duke@435 | 72 | void TimeStamp::update() { |
duke@435 | 73 | update_to(os::elapsed_counter()); |
duke@435 | 74 | } |
duke@435 | 75 | |
duke@435 | 76 | double TimeStamp::seconds() const { |
duke@435 | 77 | assert(is_updated(), "must not be clear"); |
duke@435 | 78 | jlong new_count = os::elapsed_counter(); |
duke@435 | 79 | double count = (double) new_count - _counter; |
duke@435 | 80 | double freq = (double) os::elapsed_frequency(); |
duke@435 | 81 | return count/freq; |
duke@435 | 82 | } |
duke@435 | 83 | |
duke@435 | 84 | jlong TimeStamp::milliseconds() const { |
duke@435 | 85 | assert(is_updated(), "must not be clear"); |
duke@435 | 86 | |
duke@435 | 87 | jlong new_count = os::elapsed_counter(); |
duke@435 | 88 | jlong count = new_count - _counter; |
duke@435 | 89 | jlong ticks_per_ms = os::elapsed_frequency() / 1000; |
duke@435 | 90 | return count / ticks_per_ms; |
duke@435 | 91 | } |
duke@435 | 92 | |
duke@435 | 93 | jlong TimeStamp::ticks_since_update() const { |
duke@435 | 94 | assert(is_updated(), "must not be clear"); |
duke@435 | 95 | return os::elapsed_counter() - _counter; |
duke@435 | 96 | } |
duke@435 | 97 | |
duke@435 | 98 | TraceTime::TraceTime(const char* title, |
duke@435 | 99 | bool doit, |
duke@435 | 100 | bool print_cr, |
duke@435 | 101 | outputStream* logfile) { |
duke@435 | 102 | _active = doit; |
duke@435 | 103 | _verbose = true; |
duke@435 | 104 | _print_cr = print_cr; |
duke@435 | 105 | _logfile = (logfile != NULL) ? logfile : tty; |
duke@435 | 106 | |
duke@435 | 107 | if (_active) { |
duke@435 | 108 | _accum = NULL; |
duke@435 | 109 | if (PrintGCTimeStamps) { |
duke@435 | 110 | _logfile->stamp(); |
duke@435 | 111 | _logfile->print(": "); |
duke@435 | 112 | } |
duke@435 | 113 | _logfile->print("[%s", title); |
duke@435 | 114 | _logfile->flush(); |
duke@435 | 115 | _t.start(); |
duke@435 | 116 | } |
duke@435 | 117 | } |
duke@435 | 118 | |
duke@435 | 119 | TraceTime::TraceTime(const char* title, |
duke@435 | 120 | elapsedTimer* accumulator, |
duke@435 | 121 | bool doit, |
duke@435 | 122 | bool verbose, |
duke@435 | 123 | outputStream* logfile) { |
duke@435 | 124 | _active = doit; |
duke@435 | 125 | _verbose = verbose; |
duke@435 | 126 | _print_cr = true; |
duke@435 | 127 | _logfile = (logfile != NULL) ? logfile : tty; |
duke@435 | 128 | if (_active) { |
duke@435 | 129 | if (_verbose) { |
duke@435 | 130 | if (PrintGCTimeStamps) { |
duke@435 | 131 | _logfile->stamp(); |
duke@435 | 132 | _logfile->print(": "); |
duke@435 | 133 | } |
duke@435 | 134 | _logfile->print("[%s", title); |
duke@435 | 135 | _logfile->flush(); |
duke@435 | 136 | } |
duke@435 | 137 | _accum = accumulator; |
duke@435 | 138 | _t.start(); |
duke@435 | 139 | } |
duke@435 | 140 | } |
duke@435 | 141 | |
duke@435 | 142 | TraceTime::~TraceTime() { |
duke@435 | 143 | if (_active) { |
duke@435 | 144 | _t.stop(); |
duke@435 | 145 | if (_accum!=NULL) _accum->add(_t); |
duke@435 | 146 | if (_verbose) { |
duke@435 | 147 | if (_print_cr) { |
duke@435 | 148 | _logfile->print_cr(", %3.7f secs]", _t.seconds()); |
duke@435 | 149 | } else { |
duke@435 | 150 | _logfile->print(", %3.7f secs]", _t.seconds()); |
duke@435 | 151 | } |
duke@435 | 152 | _logfile->flush(); |
duke@435 | 153 | } |
duke@435 | 154 | } |
duke@435 | 155 | } |
duke@435 | 156 | |
duke@435 | 157 | TraceCPUTime::TraceCPUTime(bool doit, |
duke@435 | 158 | bool print_cr, |
duke@435 | 159 | outputStream *logfile) : |
duke@435 | 160 | _active(doit), |
duke@435 | 161 | _print_cr(print_cr), |
duke@435 | 162 | _starting_user_time(0.0), |
duke@435 | 163 | _starting_system_time(0.0), |
duke@435 | 164 | _starting_real_time(0.0), |
duke@435 | 165 | _logfile(logfile), |
duke@435 | 166 | _error(false) { |
duke@435 | 167 | if (_active) { |
duke@435 | 168 | if (logfile != NULL) { |
duke@435 | 169 | _logfile = logfile; |
duke@435 | 170 | } else { |
duke@435 | 171 | _logfile = tty; |
duke@435 | 172 | } |
duke@435 | 173 | |
duke@435 | 174 | _error = !os::getTimesSecs(&_starting_real_time, |
duke@435 | 175 | &_starting_user_time, |
duke@435 | 176 | &_starting_system_time); |
duke@435 | 177 | } |
duke@435 | 178 | } |
duke@435 | 179 | |
duke@435 | 180 | TraceCPUTime::~TraceCPUTime() { |
duke@435 | 181 | if (_active) { |
duke@435 | 182 | bool valid = false; |
duke@435 | 183 | if (!_error) { |
duke@435 | 184 | double real_secs; // walk clock time |
duke@435 | 185 | double system_secs; // system time |
duke@435 | 186 | double user_secs; // user time for all threads |
duke@435 | 187 | |
duke@435 | 188 | double real_time, user_time, system_time; |
duke@435 | 189 | valid = os::getTimesSecs(&real_time, &user_time, &system_time); |
duke@435 | 190 | if (valid) { |
duke@435 | 191 | |
duke@435 | 192 | user_secs = user_time - _starting_user_time; |
duke@435 | 193 | system_secs = system_time - _starting_system_time; |
duke@435 | 194 | real_secs = real_time - _starting_real_time; |
duke@435 | 195 | |
duke@435 | 196 | _logfile->print(" [Times: user=%3.2f sys=%3.2f, real=%3.2f secs] ", |
duke@435 | 197 | user_secs, system_secs, real_secs); |
duke@435 | 198 | |
duke@435 | 199 | } else { |
duke@435 | 200 | _logfile->print("[Invalid result in TraceCPUTime]"); |
duke@435 | 201 | } |
duke@435 | 202 | } else { |
duke@435 | 203 | _logfile->print("[Error in TraceCPUTime]"); |
duke@435 | 204 | } |
duke@435 | 205 | if (_print_cr) { |
duke@435 | 206 | _logfile->print_cr(""); |
duke@435 | 207 | } |
duke@435 | 208 | } |
duke@435 | 209 | } |