1 /*

     2  * Copyright (c) 2012, 2013, 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 "gc_implementation/shared/gcTimer.hpp"

    27 #include "utilities/growableArray.hpp"

    28 

    29 void GCTimer::register_gc_start(jlong time) {

    30   _time_partitions.clear();

    31   _gc_start = time;

    32 }

    33 

    34 void GCTimer::register_gc_end(jlong time) {

    35   assert(!_time_partitions.has_active_phases(),

    36       "We should have ended all started phases, before ending the GC");

    37 

    38   _gc_end = time;

    39 }

    40 

    41 void GCTimer::register_gc_pause_start(const char* name, jlong time) {

    42   _time_partitions.report_gc_phase_start(name, time);

    43 }

    44 

    45 void GCTimer::register_gc_pause_end(jlong time) {

    46   _time_partitions.report_gc_phase_end(time);

    47 }

    48 

    49 void GCTimer::register_gc_phase_start(const char* name, jlong time) {

    50   _time_partitions.report_gc_phase_start(name, time);

    51 }

    52 

    53 void GCTimer::register_gc_phase_end(jlong time) {

    54   _time_partitions.report_gc_phase_end(time);

    55 }

    56 

    57 

    58 void STWGCTimer::register_gc_start(jlong time) {

    59   GCTimer::register_gc_start(time);

    60   register_gc_pause_start("GC Pause", time);

    61 }

    62 

    63 void STWGCTimer::register_gc_end(jlong time) {

    64   register_gc_pause_end(time);

    65   GCTimer::register_gc_end(time);

    66 }

    67 

    68 void ConcurrentGCTimer::register_gc_pause_start(const char* name, jlong time) {

    69   GCTimer::register_gc_pause_start(name, time);

    70 }

    71 

    72 void ConcurrentGCTimer::register_gc_pause_end(jlong time) {

    73   GCTimer::register_gc_pause_end(time);

    74 }

    75 

    76 void PhasesStack::clear() {

    77   _next_phase_level = 0;

    78 }

    79 

    80 void PhasesStack::push(int phase_index) {

    81   assert(_next_phase_level < PHASE_LEVELS, "Overflow");

    82 

    83   _phase_indices[_next_phase_level] = phase_index;

    84 

    85   _next_phase_level++;

    86 }

    87 

    88 int PhasesStack::pop() {

    89   assert(_next_phase_level > 0, "Underflow");

    90 

    91   _next_phase_level--;

    92 

    93   return _phase_indices[_next_phase_level];

    94 }

    95 

    96 int PhasesStack::count() const {

    97   return _next_phase_level;

    98 }

    99 

   100 

   101 TimePartitions::TimePartitions() {

   102   _phases = new (ResourceObj::C_HEAP, mtGC) GrowableArray<PausePhase>(INITIAL_CAPACITY, true, mtGC);

   103   clear();

   104 }

   105 

   106 TimePartitions::~TimePartitions() {

   107   delete _phases;

   108   _phases = NULL;

   109 }

   110 

   111 void TimePartitions::clear() {

   112   _phases->clear();

   113   _active_phases.clear();

   114   _sum_of_pauses = 0;

   115   _longest_pause = 0;

   116 }

   117 

   118 void TimePartitions::report_gc_phase_start(const char* name, jlong time) {

   119   assert(_phases->length() <= 1000, "Too many recored phases?");

   120 

   121   int level = _active_phases.count();

   122 

   123   PausePhase phase;

   124   phase.set_level(level);

   125   phase.set_name(name);

   126   phase.set_start(time);

   127 

   128   int index = _phases->append(phase);

   129 

   130   _active_phases.push(index);

   131 }

   132 

   133 void TimePartitions::update_statistics(GCPhase* phase) {

   134   // FIXME: This should only be done for pause phases

   135   if (phase->level() == 0) {

   136     jlong pause = phase->end() - phase->start();

   137     _sum_of_pauses += pause;

   138     _longest_pause = MAX2(pause, _longest_pause);

   139   }

   140 }

   141 

   142 void TimePartitions::report_gc_phase_end(jlong time) {

   143   int phase_index = _active_phases.pop();

   144   GCPhase* phase = _phases->adr_at(phase_index);

   145   phase->set_end(time);

   146   update_statistics(phase);

   147 }

   148 

   149 int TimePartitions::num_phases() const {

   150   return _phases->length();

   151 }

   152 

   153 GCPhase* TimePartitions::phase_at(int index) const {

   154   assert(index >= 0, "Out of bounds");

   155   assert(index < _phases->length(), "Out of bounds");

   156 

   157   return _phases->adr_at(index);

   158 }

   159 

   160 jlong TimePartitions::sum_of_pauses() {

   161   return _sum_of_pauses;

   162 }

   163 

   164 jlong TimePartitions::longest_pause() {

   165   return _longest_pause;

   166 }

   167 

   168 bool TimePartitions::has_active_phases() {

   169   return _active_phases.count() > 0;

   170 }

   171 

   172 bool TimePartitionPhasesIterator::has_next() {

   173   return _next < _time_partitions->num_phases();

   174 }

   175 

   176 GCPhase* TimePartitionPhasesIterator::next() {

   177   assert(has_next(), "Must have phases left");

   178   return _time_partitions->phase_at(_next++);

   179 }

   180 

   181 

   182 /////////////// Unit tests ///////////////

   183 

   184 #ifndef PRODUCT

   185 

   186 class TimePartitionPhasesIteratorTest {

   187  public:

   188   static void all() {

   189     one_pause();

   190     two_pauses();

   191     one_sub_pause_phase();

   192     many_sub_pause_phases();

   193     many_sub_pause_phases2();

   194     max_nested_pause_phases();

   195   }

   196 

   197   static void validate_pause_phase(GCPhase* phase, int level, const char* name, jlong start, jlong end) {

   198     assert(phase->level() == level, "Incorrect level");

   199     assert(strcmp(phase->name(), name) == 0, "Incorrect name");

   200     assert(phase->start() == start, "Incorrect start");

   201     assert(phase->end() == end, "Incorrect end");

   202   }

   203 

   204   static void one_pause() {

   205     TimePartitions time_partitions;

   206     time_partitions.report_gc_phase_start("PausePhase", 2);

   207     time_partitions.report_gc_phase_end(8);

   208 

   209     TimePartitionPhasesIterator iter(&time_partitions);

   210 

   211     validate_pause_phase(iter.next(), 0, "PausePhase", 2, 8);

   212     assert(time_partitions.sum_of_pauses() == 8-2, "Incorrect");

   213     assert(time_partitions.longest_pause() == 8-2, "Incorrect");

   214 

   215     assert(!iter.has_next(), "Too many elements");

   216   }

   217 

   218   static void two_pauses() {

   219     TimePartitions time_partitions;

   220     time_partitions.report_gc_phase_start("PausePhase1", 2);

   221     time_partitions.report_gc_phase_end(3);

   222     time_partitions.report_gc_phase_start("PausePhase2", 4);

   223     time_partitions.report_gc_phase_end(6);

   224 

   225     TimePartitionPhasesIterator iter(&time_partitions);

   226 

   227     validate_pause_phase(iter.next(), 0, "PausePhase1", 2, 3);

   228     validate_pause_phase(iter.next(), 0, "PausePhase2", 4, 6);

   229 

   230     assert(time_partitions.sum_of_pauses() == 3, "Incorrect");

   231     assert(time_partitions.longest_pause() == 2, "Incorrect");

   232 

   233     assert(!iter.has_next(), "Too many elements");

   234   }

   235 

   236   static void one_sub_pause_phase() {

   237     TimePartitions time_partitions;

   238     time_partitions.report_gc_phase_start("PausePhase", 2);

   239     time_partitions.report_gc_phase_start("SubPhase", 3);

   240     time_partitions.report_gc_phase_end(4);

   241     time_partitions.report_gc_phase_end(5);

   242 

   243     TimePartitionPhasesIterator iter(&time_partitions);

   244 

   245     validate_pause_phase(iter.next(), 0, "PausePhase", 2, 5);

   246     validate_pause_phase(iter.next(), 1, "SubPhase", 3, 4);

   247 

   248     assert(time_partitions.sum_of_pauses() == 3, "Incorrect");

   249     assert(time_partitions.longest_pause() == 3, "Incorrect");

   250 

   251     assert(!iter.has_next(), "Too many elements");

   252   }

   253 

   254   static void max_nested_pause_phases() {

   255     TimePartitions time_partitions;

   256     time_partitions.report_gc_phase_start("PausePhase", 2);

   257     time_partitions.report_gc_phase_start("SubPhase1", 3);

   258     time_partitions.report_gc_phase_start("SubPhase2", 4);

   259     time_partitions.report_gc_phase_start("SubPhase3", 5);

   260     time_partitions.report_gc_phase_end(6);

   261     time_partitions.report_gc_phase_end(7);

   262     time_partitions.report_gc_phase_end(8);

   263     time_partitions.report_gc_phase_end(9);

   264 

   265     TimePartitionPhasesIterator iter(&time_partitions);

   266 

   267     validate_pause_phase(iter.next(), 0, "PausePhase", 2, 9);

   268     validate_pause_phase(iter.next(), 1, "SubPhase1", 3, 8);

   269     validate_pause_phase(iter.next(), 2, "SubPhase2", 4, 7);

   270     validate_pause_phase(iter.next(), 3, "SubPhase3", 5, 6);

   271 

   272     assert(time_partitions.sum_of_pauses() == 7, "Incorrect");

   273     assert(time_partitions.longest_pause() == 7, "Incorrect");

   274 

   275     assert(!iter.has_next(), "Too many elements");

   276   }

   277 

   278   static void many_sub_pause_phases() {

   279     TimePartitions time_partitions;

   280     time_partitions.report_gc_phase_start("PausePhase", 2);

   281 

   282     time_partitions.report_gc_phase_start("SubPhase1", 3);

   283     time_partitions.report_gc_phase_end(4);

   284     time_partitions.report_gc_phase_start("SubPhase2", 5);

   285     time_partitions.report_gc_phase_end(6);

   286     time_partitions.report_gc_phase_start("SubPhase3", 7);

   287     time_partitions.report_gc_phase_end(8);

   288     time_partitions.report_gc_phase_start("SubPhase4", 9);

   289     time_partitions.report_gc_phase_end(10);

   290 

   291     time_partitions.report_gc_phase_end(11);

   292 

   293     TimePartitionPhasesIterator iter(&time_partitions);

   294 

   295     validate_pause_phase(iter.next(), 0, "PausePhase", 2, 11);

   296     validate_pause_phase(iter.next(), 1, "SubPhase1", 3, 4);

   297     validate_pause_phase(iter.next(), 1, "SubPhase2", 5, 6);

   298     validate_pause_phase(iter.next(), 1, "SubPhase3", 7, 8);

   299     validate_pause_phase(iter.next(), 1, "SubPhase4", 9, 10);

   300 

   301     assert(time_partitions.sum_of_pauses() == 9, "Incorrect");

   302     assert(time_partitions.longest_pause() == 9, "Incorrect");

   303 

   304     assert(!iter.has_next(), "Too many elements");

   305   }

   306 

   307   static void many_sub_pause_phases2() {

   308     TimePartitions time_partitions;

   309     time_partitions.report_gc_phase_start("PausePhase", 2);

   310 

   311     time_partitions.report_gc_phase_start("SubPhase1", 3);

   312     time_partitions.report_gc_phase_start("SubPhase11", 4);

   313     time_partitions.report_gc_phase_end(5);

   314     time_partitions.report_gc_phase_start("SubPhase12", 6);

   315     time_partitions.report_gc_phase_end(7);

   316     time_partitions.report_gc_phase_end(8);

   317     time_partitions.report_gc_phase_start("SubPhase2", 9);

   318     time_partitions.report_gc_phase_start("SubPhase21", 10);

   319     time_partitions.report_gc_phase_end(11);

   320     time_partitions.report_gc_phase_start("SubPhase22", 12);

   321     time_partitions.report_gc_phase_end(13);

   322     time_partitions.report_gc_phase_end(14);

   323     time_partitions.report_gc_phase_start("SubPhase3", 15);

   324     time_partitions.report_gc_phase_end(16);

   325 

   326     time_partitions.report_gc_phase_end(17);

   327 

   328     TimePartitionPhasesIterator iter(&time_partitions);

   329 

   330     validate_pause_phase(iter.next(), 0, "PausePhase", 2, 17);

   331     validate_pause_phase(iter.next(), 1, "SubPhase1", 3, 8);

   332     validate_pause_phase(iter.next(), 2, "SubPhase11", 4, 5);

   333     validate_pause_phase(iter.next(), 2, "SubPhase12", 6, 7);

   334     validate_pause_phase(iter.next(), 1, "SubPhase2", 9, 14);

   335     validate_pause_phase(iter.next(), 2, "SubPhase21", 10, 11);

   336     validate_pause_phase(iter.next(), 2, "SubPhase22", 12, 13);

   337     validate_pause_phase(iter.next(), 1, "SubPhase3", 15, 16);

   338 

   339     assert(time_partitions.sum_of_pauses() == 15, "Incorrect");

   340     assert(time_partitions.longest_pause() == 15, "Incorrect");

   341 

   342     assert(!iter.has_next(), "Too many elements");

   343   }

   344 };

   345 

   346 class GCTimerTest {

   347 public:

   348   static void all() {

   349     gc_start();

   350     gc_end();

   351   }

   352 

   353   static void gc_start() {

   354     GCTimer gc_timer;

   355     gc_timer.register_gc_start(1);

   356 

   357     assert(gc_timer.gc_start() == 1, "Incorrect");

   358   }

   359 

   360   static void gc_end() {

   361     GCTimer gc_timer;

   362     gc_timer.register_gc_start(1);

   363     gc_timer.register_gc_end(2);

   364 

   365     assert(gc_timer.gc_end() == 2, "Incorrect");

   366   }

   367 };

   368 

   369 void GCTimerAllTest::all() {

   370   GCTimerTest::all();

   371   TimePartitionPhasesIteratorTest::all();

   372 }

   373 

   374 #endif