*** old/src/share/vm/gc_implementation/g1/g1CollectedHeap.cpp	Fri Sep 14 10:36:20 2012
--- new/src/share/vm/gc_implementation/g1/g1CollectedHeap.cpp	Fri Sep 14 10:36:17 2012

*** 3661,3670 ****
--- 3661,3709 ----
      task_queue(i)->stats.reset();
    }
  }
  #endif // TASKQUEUE_STATS
  
+ void G1CollectedHeap::log_gc_header() {
+   if (!G1Log::fine()) {
+     return;
+   }
+   gclog_or_tty->date_stamp(PrintGCDateStamps);
+   if (PrintGCTimeStamps) {
+     gclog_or_tty->stamp();
+     gclog_or_tty->print(": ");
+   }
+ 
+   GCCauseString gc_cause_str = GCCauseString("GC pause", gc_cause())
+     .append(g1_policy()->gcs_are_young() ? " (young)" : " (mixed)")
+     .append(g1_policy()->during_initial_mark_pause() ? " (initial-mark)" : "");
+ 
+   gclog_or_tty->print("[%s", (const char*)gc_cause_str);
+ }
+ 
+ void G1CollectedHeap::log_gc_footer(double pause_time_sec) {
+   if (!G1Log::fine()) {
+     return;
+   }
+ 
+   if (G1Log::finer()) {
+     if (evacuation_failed()) {
+       gclog_or_tty->print(" (to-space exhausted)");
+     }
+     gclog_or_tty->print_cr(", %3.7f secs]", pause_time_sec);
+     g1_policy()->phase_times()->note_gc_end();
+     g1_policy()->phase_times()->print(pause_time_sec);
+     g1_policy()->print_detailed_heap_transition();
+   } else {
+     if (evacuation_failed()) {
+       gclog_or_tty->print("--");
+     }
+     g1_policy()->print_heap_transition();
+     gclog_or_tty->print_cr(", %3.7f secs]", pause_time_sec);
+   }
+ }
+ 
  bool
  G1CollectedHeap::do_collection_pause_at_safepoint(double target_pause_time_ms) {
    assert_at_safepoint(true /* should_be_vm_thread */);
    guarantee(!is_gc_active(), "collection is not reentrant");
  

*** 3703,3723 ****
--- 3742,3758 ----
      if (g1_policy()->during_initial_mark_pause()) {
        // We are about to start a marking cycle, so we increment the
        // full collection counter.
        increment_old_marking_cycles_started();
      }
      // if the log level is "finer" is on, we'll print long statistics information
      // in the collector policy code, so let's not print this as the output
      // is messy if we do.
      gclog_or_tty->date_stamp(G1Log::fine() && PrintGCDateStamps);
      TraceCPUTime tcpu(G1Log::finer(), true, gclog_or_tty);
  
      int active_workers = (G1CollectedHeap::use_parallel_gc_threads() ?
                                  workers()->active_workers() : 1);
      double pause_start_sec = os::elapsedTime();
      g1_policy()->phase_times()->note_gc_start(active_workers);
!     bool initial_mark_gc = g1_policy()->during_initial_mark_pause();
!     log_gc_header();
  
      TraceCollectorStats tcs(g1mm()->incremental_collection_counters());
      TraceMemoryManagerStats tms(false /* fullGC */, gc_cause());
  
      // If the secondary_free_list is not empty, append it to the

*** 4010,4048 ****
--- 4045,4055 ----
        ParallelTaskTerminator::print_termination_counts();
  #endif
  
        gc_epilogue(false);
  
        if (G1Log::fine()) {
          if (PrintGCTimeStamps) {
            gclog_or_tty->stamp();
            gclog_or_tty->print(": ");
          }
  
          GCCauseString gc_cause_str = GCCauseString("GC pause", gc_cause())
            .append(g1_policy()->gcs_are_young() ? " (young)" : " (mixed)")
            .append(initial_mark_gc ? " (initial-mark)" : "");
  
          double pause_time_sec = os::elapsedTime() - pause_start_sec;
  
          if (G1Log::finer()) {
            if (evacuation_failed()) {
              gc_cause_str.append(" (to-space exhausted)");
            }
            gclog_or_tty->print_cr("[%s, %3.7f secs]", (const char*)gc_cause_str, pause_time_sec);
            g1_policy()->phase_times()->note_gc_end();
            g1_policy()->phase_times()->print(pause_time_sec);
            g1_policy()->print_detailed_heap_transition();
          } else {
            if (evacuation_failed()) {
              gc_cause_str.append("--");
            }
            gclog_or_tty->print("[%s", (const char*)gc_cause_str);
        g1_policy()->print_heap_transition();
            gclog_or_tty->print_cr(", %3.7f secs]", pause_time_sec);
          }
        }
+       log_gc_footer(os::elapsedTime() - pause_start_sec);
      }
  
      // It is not yet to safe to tell the concurrent mark to
      // start as we have some optional output below. We don't want the
      // output from the concurrent mark thread interfering with this