hotspot/src/share/vm/gc/shared/gcTimer.cpp
changeset 35204 78a0fd90a70f
parent 30764 fec48bf5a827
child 35529 39376b4613b5
equal deleted inserted replaced
35202:506ccf1717fd 35204:78a0fd90a70f
    67   register_gc_pause_end(time);
    67   register_gc_pause_end(time);
    68   GCTimer::register_gc_end(time);
    68   GCTimer::register_gc_end(time);
    69 }
    69 }
    70 
    70 
    71 void ConcurrentGCTimer::register_gc_pause_start(const char* name) {
    71 void ConcurrentGCTimer::register_gc_pause_start(const char* name) {
       
    72   assert(!_is_concurrent_phase_active, "A pause phase can't be started while a concurrent phase is active.");
    72   GCTimer::register_gc_pause_start(name);
    73   GCTimer::register_gc_pause_start(name);
    73 }
    74 }
    74 
    75 
    75 void ConcurrentGCTimer::register_gc_pause_end() {
    76 void ConcurrentGCTimer::register_gc_pause_end() {
       
    77   assert(!_is_concurrent_phase_active, "A pause phase can't be ended while a concurrent phase is active.");
    76   GCTimer::register_gc_pause_end();
    78   GCTimer::register_gc_pause_end();
       
    79 }
       
    80 
       
    81 void ConcurrentGCTimer::register_gc_concurrent_start(const char* name, const Ticks& time) {
       
    82   assert(!_is_concurrent_phase_active, "A concurrent phase is already active.");
       
    83   _time_partitions.report_gc_phase_start(name, time, GCPhase::ConcurrentPhaseType);
       
    84   _is_concurrent_phase_active = true;
       
    85 }
       
    86 
       
    87 void ConcurrentGCTimer::register_gc_concurrent_end(const Ticks& time) {
       
    88   assert(_is_concurrent_phase_active, "A concurrent phase is not active.");
       
    89   _time_partitions.report_gc_phase_end(time, GCPhase::ConcurrentPhaseType);
       
    90   _is_concurrent_phase_active = false;
    77 }
    91 }
    78 
    92 
    79 void PhasesStack::clear() {
    93 void PhasesStack::clear() {
    80   _next_phase_level = 0;
    94   _next_phase_level = 0;
    81 }
    95 }
    82 
    96 
    83 void PhasesStack::push(int phase_index) {
    97 void PhasesStack::push(int phase_index) {
    84   assert(_next_phase_level < PHASE_LEVELS, "Overflow");
    98   assert(_next_phase_level < PHASE_LEVELS, "Overflow");
    85 
    99 
    86   _phase_indices[_next_phase_level] = phase_index;
   100   _phase_indices[_next_phase_level] = phase_index;
    87 
       
    88   _next_phase_level++;
   101   _next_phase_level++;
    89 }
   102 }
    90 
   103 
    91 int PhasesStack::pop() {
   104 int PhasesStack::pop() {
    92   assert(_next_phase_level > 0, "Underflow");
   105   assert(_next_phase_level > 0, "Underflow");
    93 
   106 
    94   _next_phase_level--;
   107   _next_phase_level--;
    95 
       
    96   return _phase_indices[_next_phase_level];
   108   return _phase_indices[_next_phase_level];
    97 }
   109 }
    98 
   110 
    99 int PhasesStack::count() const {
   111 int PhasesStack::count() const {
   100   return _next_phase_level;
   112   return _next_phase_level;
   101 }
   113 }
   102 
   114 
   103 
       
   104 TimePartitions::TimePartitions() {
   115 TimePartitions::TimePartitions() {
   105   _phases = new (ResourceObj::C_HEAP, mtGC) GrowableArray<PausePhase>(INITIAL_CAPACITY, true, mtGC);
   116   _phases = new (ResourceObj::C_HEAP, mtGC) GrowableArray<GCPhase>(INITIAL_CAPACITY, true, mtGC);
   106   clear();
   117   clear();
   107 }
   118 }
   108 
   119 
   109 TimePartitions::~TimePartitions() {
   120 TimePartitions::~TimePartitions() {
   110   delete _phases;
   121   delete _phases;
   116   _active_phases.clear();
   127   _active_phases.clear();
   117   _sum_of_pauses = Tickspan();
   128   _sum_of_pauses = Tickspan();
   118   _longest_pause = Tickspan();
   129   _longest_pause = Tickspan();
   119 }
   130 }
   120 
   131 
   121 void TimePartitions::report_gc_phase_start(const char* name, const Ticks& time) {
   132 void TimePartitions::report_gc_phase_start(const char* name, const Ticks& time, GCPhase::PhaseType type) {
   122   assert(_phases->length() <= 1000, "Too many recored phases?");
   133   assert(_phases->length() <= 1000, "Too many recored phases?");
   123 
   134 
   124   int level = _active_phases.count();
   135   int level = _active_phases.count();
   125 
   136 
   126   PausePhase phase;
   137   GCPhase phase;
       
   138   phase.set_type(type);
   127   phase.set_level(level);
   139   phase.set_level(level);
   128   phase.set_name(name);
   140   phase.set_name(name);
   129   phase.set_start(time);
   141   phase.set_start(time);
   130 
   142 
   131   int index = _phases->append(phase);
   143   int index = _phases->append(phase);
   132 
   144 
   133   _active_phases.push(index);
   145   _active_phases.push(index);
   134 }
   146 }
   135 
   147 
   136 void TimePartitions::update_statistics(GCPhase* phase) {
   148 void TimePartitions::update_statistics(GCPhase* phase) {
   137   // FIXME: This should only be done for pause phases
   149   if ((phase->type() == GCPhase::PausePhaseType) && (phase->level() == 0)) {
   138   if (phase->level() == 0) {
       
   139     const Tickspan pause = phase->end() - phase->start();
   150     const Tickspan pause = phase->end() - phase->start();
   140     _sum_of_pauses += pause;
   151     _sum_of_pauses += pause;
   141     _longest_pause = MAX2(pause, _longest_pause);
   152     _longest_pause = MAX2(pause, _longest_pause);
   142   }
   153   }
   143 }
   154 }
   144 
   155 
   145 void TimePartitions::report_gc_phase_end(const Ticks& time) {
   156 void TimePartitions::report_gc_phase_end(const Ticks& time, GCPhase::PhaseType type) {
   146   int phase_index = _active_phases.pop();
   157   int phase_index = _active_phases.pop();
   147   GCPhase* phase = _phases->adr_at(phase_index);
   158   GCPhase* phase = _phases->adr_at(phase_index);
   148   phase->set_end(time);
   159   phase->set_end(time);
   149   update_statistics(phase);
   160   update_statistics(phase);
   150 }
   161 }
   185     two_pauses();
   196     two_pauses();
   186     one_sub_pause_phase();
   197     one_sub_pause_phase();
   187     many_sub_pause_phases();
   198     many_sub_pause_phases();
   188     many_sub_pause_phases2();
   199     many_sub_pause_phases2();
   189     max_nested_pause_phases();
   200     max_nested_pause_phases();
   190   }
   201     one_concurrent();
   191 
   202   }
   192   static void validate_pause_phase(GCPhase* phase, int level, const char* name, const Ticks& start, const Ticks& end) {
   203 
       
   204   static void validate_gc_phase(GCPhase* phase, int level, const char* name, const Ticks& start, const Ticks& end) {
   193     assert(phase->level() == level, "Incorrect level");
   205     assert(phase->level() == level, "Incorrect level");
   194     assert(strcmp(phase->name(), name) == 0, "Incorrect name");
   206     assert(strcmp(phase->name(), name) == 0, "Incorrect name");
   195     assert(phase->start() == start, "Incorrect start");
   207     assert(phase->start() == start, "Incorrect start");
   196     assert(phase->end() == end, "Incorrect end");
   208     assert(phase->end() == end, "Incorrect end");
   197   }
   209   }
   201     time_partitions.report_gc_phase_start("PausePhase", 2);
   213     time_partitions.report_gc_phase_start("PausePhase", 2);
   202     time_partitions.report_gc_phase_end(8);
   214     time_partitions.report_gc_phase_end(8);
   203 
   215 
   204     TimePartitionPhasesIterator iter(&time_partitions);
   216     TimePartitionPhasesIterator iter(&time_partitions);
   205 
   217 
   206     validate_pause_phase(iter.next(), 0, "PausePhase", 2, 8);
   218     validate_gc_phase(iter.next(), 0, "PausePhase", 2, 8);
   207     assert(time_partitions.sum_of_pauses() == Ticks(8) - Ticks(2), "Incorrect");
   219     assert(time_partitions.sum_of_pauses() == Ticks(8) - Ticks(2), "Incorrect");
   208     assert(time_partitions.longest_pause() == Ticks(8) - Ticks(2), "Incorrect");
   220     assert(time_partitions.longest_pause() == Ticks(8) - Ticks(2), "Incorrect");
   209 
   221 
   210     assert(!iter.has_next(), "Too many elements");
   222     assert(!iter.has_next(), "Too many elements");
   211   }
   223   }
   217     time_partitions.report_gc_phase_start("PausePhase2", 4);
   229     time_partitions.report_gc_phase_start("PausePhase2", 4);
   218     time_partitions.report_gc_phase_end(6);
   230     time_partitions.report_gc_phase_end(6);
   219 
   231 
   220     TimePartitionPhasesIterator iter(&time_partitions);
   232     TimePartitionPhasesIterator iter(&time_partitions);
   221 
   233 
   222     validate_pause_phase(iter.next(), 0, "PausePhase1", 2, 3);
   234     validate_gc_phase(iter.next(), 0, "PausePhase1", 2, 3);
   223     validate_pause_phase(iter.next(), 0, "PausePhase2", 4, 6);
   235     validate_gc_phase(iter.next(), 0, "PausePhase2", 4, 6);
   224 
   236 
   225     assert(time_partitions.sum_of_pauses() == Ticks(3) - Ticks(0), "Incorrect");
   237     assert(time_partitions.sum_of_pauses() == Ticks(3) - Ticks(0), "Incorrect");
   226     assert(time_partitions.longest_pause() == Ticks(2) - Ticks(0), "Incorrect");
   238     assert(time_partitions.longest_pause() == Ticks(2) - Ticks(0), "Incorrect");
   227 
   239 
   228     assert(!iter.has_next(), "Too many elements");
   240     assert(!iter.has_next(), "Too many elements");
   235     time_partitions.report_gc_phase_end(4);
   247     time_partitions.report_gc_phase_end(4);
   236     time_partitions.report_gc_phase_end(5);
   248     time_partitions.report_gc_phase_end(5);
   237 
   249 
   238     TimePartitionPhasesIterator iter(&time_partitions);
   250     TimePartitionPhasesIterator iter(&time_partitions);
   239 
   251 
   240     validate_pause_phase(iter.next(), 0, "PausePhase", 2, 5);
   252     validate_gc_phase(iter.next(), 0, "PausePhase", 2, 5);
   241     validate_pause_phase(iter.next(), 1, "SubPhase", 3, 4);
   253     validate_gc_phase(iter.next(), 1, "SubPhase", 3, 4);
   242 
   254 
   243     assert(time_partitions.sum_of_pauses() == Ticks(3) - Ticks(0), "Incorrect");
   255     assert(time_partitions.sum_of_pauses() == Ticks(3) - Ticks(0), "Incorrect");
   244     assert(time_partitions.longest_pause() == Ticks(3) - Ticks(0), "Incorrect");
   256     assert(time_partitions.longest_pause() == Ticks(3) - Ticks(0), "Incorrect");
   245 
   257 
   246     assert(!iter.has_next(), "Too many elements");
   258     assert(!iter.has_next(), "Too many elements");
   257     time_partitions.report_gc_phase_end(8);
   269     time_partitions.report_gc_phase_end(8);
   258     time_partitions.report_gc_phase_end(9);
   270     time_partitions.report_gc_phase_end(9);
   259 
   271 
   260     TimePartitionPhasesIterator iter(&time_partitions);
   272     TimePartitionPhasesIterator iter(&time_partitions);
   261 
   273 
   262     validate_pause_phase(iter.next(), 0, "PausePhase", 2, 9);
   274     validate_gc_phase(iter.next(), 0, "PausePhase", 2, 9);
   263     validate_pause_phase(iter.next(), 1, "SubPhase1", 3, 8);
   275     validate_gc_phase(iter.next(), 1, "SubPhase1", 3, 8);
   264     validate_pause_phase(iter.next(), 2, "SubPhase2", 4, 7);
   276     validate_gc_phase(iter.next(), 2, "SubPhase2", 4, 7);
   265     validate_pause_phase(iter.next(), 3, "SubPhase3", 5, 6);
   277     validate_gc_phase(iter.next(), 3, "SubPhase3", 5, 6);
   266 
   278 
   267     assert(time_partitions.sum_of_pauses() == Ticks(7) - Ticks(0), "Incorrect");
   279     assert(time_partitions.sum_of_pauses() == Ticks(7) - Ticks(0), "Incorrect");
   268     assert(time_partitions.longest_pause() == Ticks(7) - Ticks(0), "Incorrect");
   280     assert(time_partitions.longest_pause() == Ticks(7) - Ticks(0), "Incorrect");
   269 
   281 
   270     assert(!iter.has_next(), "Too many elements");
   282     assert(!iter.has_next(), "Too many elements");
   285 
   297 
   286     time_partitions.report_gc_phase_end(11);
   298     time_partitions.report_gc_phase_end(11);
   287 
   299 
   288     TimePartitionPhasesIterator iter(&time_partitions);
   300     TimePartitionPhasesIterator iter(&time_partitions);
   289 
   301 
   290     validate_pause_phase(iter.next(), 0, "PausePhase", 2, 11);
   302     validate_gc_phase(iter.next(), 0, "PausePhase", 2, 11);
   291     validate_pause_phase(iter.next(), 1, "SubPhase1", 3, 4);
   303     validate_gc_phase(iter.next(), 1, "SubPhase1", 3, 4);
   292     validate_pause_phase(iter.next(), 1, "SubPhase2", 5, 6);
   304     validate_gc_phase(iter.next(), 1, "SubPhase2", 5, 6);
   293     validate_pause_phase(iter.next(), 1, "SubPhase3", 7, 8);
   305     validate_gc_phase(iter.next(), 1, "SubPhase3", 7, 8);
   294     validate_pause_phase(iter.next(), 1, "SubPhase4", 9, 10);
   306     validate_gc_phase(iter.next(), 1, "SubPhase4", 9, 10);
   295 
   307 
   296     assert(time_partitions.sum_of_pauses() == Ticks(9) - Ticks(0), "Incorrect");
   308     assert(time_partitions.sum_of_pauses() == Ticks(9) - Ticks(0), "Incorrect");
   297     assert(time_partitions.longest_pause() == Ticks(9) - Ticks(0), "Incorrect");
   309     assert(time_partitions.longest_pause() == Ticks(9) - Ticks(0), "Incorrect");
   298 
   310 
   299     assert(!iter.has_next(), "Too many elements");
   311     assert(!iter.has_next(), "Too many elements");
   320 
   332 
   321     time_partitions.report_gc_phase_end(17);
   333     time_partitions.report_gc_phase_end(17);
   322 
   334 
   323     TimePartitionPhasesIterator iter(&time_partitions);
   335     TimePartitionPhasesIterator iter(&time_partitions);
   324 
   336 
   325     validate_pause_phase(iter.next(), 0, "PausePhase", 2, 17);
   337     validate_gc_phase(iter.next(), 0, "PausePhase", 2, 17);
   326     validate_pause_phase(iter.next(), 1, "SubPhase1", 3, 8);
   338     validate_gc_phase(iter.next(), 1, "SubPhase1", 3, 8);
   327     validate_pause_phase(iter.next(), 2, "SubPhase11", 4, 5);
   339     validate_gc_phase(iter.next(), 2, "SubPhase11", 4, 5);
   328     validate_pause_phase(iter.next(), 2, "SubPhase12", 6, 7);
   340     validate_gc_phase(iter.next(), 2, "SubPhase12", 6, 7);
   329     validate_pause_phase(iter.next(), 1, "SubPhase2", 9, 14);
   341     validate_gc_phase(iter.next(), 1, "SubPhase2", 9, 14);
   330     validate_pause_phase(iter.next(), 2, "SubPhase21", 10, 11);
   342     validate_gc_phase(iter.next(), 2, "SubPhase21", 10, 11);
   331     validate_pause_phase(iter.next(), 2, "SubPhase22", 12, 13);
   343     validate_gc_phase(iter.next(), 2, "SubPhase22", 12, 13);
   332     validate_pause_phase(iter.next(), 1, "SubPhase3", 15, 16);
   344     validate_gc_phase(iter.next(), 1, "SubPhase3", 15, 16);
   333 
   345 
   334     assert(time_partitions.sum_of_pauses() == Ticks(15) - Ticks(0), "Incorrect");
   346     assert(time_partitions.sum_of_pauses() == Ticks(15) - Ticks(0), "Incorrect");
   335     assert(time_partitions.longest_pause() == Ticks(15) - Ticks(0), "Incorrect");
   347     assert(time_partitions.longest_pause() == Ticks(15) - Ticks(0), "Incorrect");
       
   348 
       
   349     assert(!iter.has_next(), "Too many elements");
       
   350   }
       
   351 
       
   352   static void one_concurrent() {
       
   353     TimePartitions time_partitions;
       
   354     time_partitions.report_gc_phase_start("ConcurrentPhase", 2, GCPhase::ConcurrentPhaseType);
       
   355     time_partitions.report_gc_phase_end(8, GCPhase::ConcurrentPhaseType);
       
   356 
       
   357     TimePartitionPhasesIterator iter(&time_partitions);
       
   358 
       
   359     validate_gc_phase(iter.next(), 0, "ConcurrentPhase", 2, 8);
       
   360     // ConcurrentPhaseType should not affect to both 'sum_of_pauses()' and 'longest_pause()'.
       
   361     assert(time_partitions.sum_of_pauses() == Tickspan(), "Incorrect");
       
   362     assert(time_partitions.longest_pause() == Tickspan(), "Incorrect");
   336 
   363 
   337     assert(!iter.has_next(), "Too many elements");
   364     assert(!iter.has_next(), "Too many elements");
   338   }
   365   }
   339 };
   366 };
   340 
   367