Mercurial > hg > openjdk > jdk9 > hotspot

changeset 12725:cded24619229

Find changesets by keywords (author, files, the commit message), revision number or hash, or revset expression.
8177963: Parallel GC fails fast when per-thread task log overflows Summary: Instead of exiting the VM when per-thread task log overflows, print warnings once and ignore any further log addition attempt. Reviewed-by: ysr, kbarrett, sangheki
author ysr
date Fri, 07 Apr 2017 10:45:26 +0200
parents 83f1f2fad2a5
children d80c43d9a99e
files src/share/vm/gc/parallel/gcTaskThread.cpp src/share/vm/gc/parallel/gcTaskThread.hpp src/share/vm/runtime/globals.hpp test/gc/parallel/TestPrintGCDetailsVerbose.java test/native/runtime/test_globals.cpp
diffstat 5 files changed, 37 insertions(+), 24 deletions(-) [+]
line wrap: on
line diff
--- a/src/share/vm/gc/parallel/gcTaskThread.cpp	Thu Apr 06 18:00:50 2017 +0000
+++ b/src/share/vm/gc/parallel/gcTaskThread.cpp	Fri Apr 07 10:45:26 2017 +0200
@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2002, 2016, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2002, 2017, Oracle and/or its affiliates. All rights reserved.
  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
  *
  * This code is free software; you can redistribute it and/or modify it
@@ -54,8 +54,26 @@
   }
 }
 
+void GCTaskThread::add_task_timestamp(const char* name, jlong t_entry, jlong t_exit) {
+  if (_time_stamp_index < GCTaskTimeStampEntries) {
+    GCTaskTimeStamp* time_stamp = time_stamp_at(_time_stamp_index);
+    time_stamp->set_name(name);
+    time_stamp->set_entry_time(t_entry);
+    time_stamp->set_exit_time(t_exit);
+  } else {
+    if (_time_stamp_index ==  GCTaskTimeStampEntries) {
+      log_warning(gc, task, time)("GC-thread %u: Too many timestamps, ignoring future ones. "
+                                  "Increase GCTaskTimeStampEntries to get more info.",
+                                  id());
+    }
+    // Let _time_stamp_index keep counting to give the user an idea about how many
+    // are needed.
+  }
+  _time_stamp_index++;
+}
+
 GCTaskTimeStamp* GCTaskThread::time_stamp_at(uint index) {
-  guarantee(index < GCTaskTimeStampEntries, "increase GCTaskTimeStampEntries");
+  assert(index < GCTaskTimeStampEntries, "Precondition");
   if (_time_stamps == NULL) {
     // We allocate the _time_stamps array lazily since logging can be enabled dynamically
     GCTaskTimeStamp* time_stamps = NEW_C_HEAP_ARRAY(GCTaskTimeStamp, GCTaskTimeStampEntries, mtGC);
@@ -65,7 +83,6 @@
       FREE_C_HEAP_ARRAY(GCTaskTimeStamp, time_stamps);
     }
   }
-
   return &(_time_stamps[index]);
 }
 
@@ -75,8 +92,11 @@
   // Since _time_stamps is now lazily allocated we need to check that it
   // has in fact been allocated when calling this function.
   if (_time_stamps != NULL) {
-    log_debug(gc, task, time)("GC-Thread %u entries: %d", id(), _time_stamp_index);
-    for(uint i=0; i<_time_stamp_index; i++) {
+    log_debug(gc, task, time)("GC-Thread %u entries: %d%s", id(),
+                              _time_stamp_index,
+                              _time_stamp_index >= GCTaskTimeStampEntries ? " (overflow)" : "");
+    const uint max_index = MIN2(_time_stamp_index, GCTaskTimeStampEntries);
+    for (uint i = 0; i < max_index; i++) {
       GCTaskTimeStamp* time_stamp = time_stamp_at(i);
       log_debug(gc, task, time)("\t[ %s " JLONG_FORMAT " " JLONG_FORMAT " ]",
                                 time_stamp->name(),
@@ -144,16 +164,7 @@
 
         if (log_is_enabled(Debug, gc, task, time)) {
           timer.update();
-
-          GCTaskTimeStamp* time_stamp = time_stamp_at(_time_stamp_index);
-
-          time_stamp->set_name(name);
-          time_stamp->set_entry_time(entry_time);
-          time_stamp->set_exit_time(timer.ticks());
-
-          // Update the index after we have set up the entry correctly since
-          // GCTaskThread::print_task_time_stamps() may read this value concurrently.
-          _time_stamp_index++;
+          add_task_timestamp(name, entry_time, timer.ticks());
         }
       } else {
         // idle tasks complete outside the normal accounting
--- a/src/share/vm/gc/parallel/gcTaskThread.hpp	Thu Apr 06 18:00:50 2017 +0000
+++ b/src/share/vm/gc/parallel/gcTaskThread.hpp	Fri Apr 07 10:45:26 2017 +0200
@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2002, 2016, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2002, 2017, Oracle and/or its affiliates. All rights reserved.
  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
  *
  * This code is free software; you can redistribute it and/or modify it
@@ -45,6 +45,7 @@
   uint _time_stamp_index;
 
   GCTaskTimeStamp* time_stamp_at(uint index);
+  void add_task_timestamp(const char* name, jlong t_entry, jlong t_exit);
 
   bool _is_working;                     // True if participating in GC tasks
 
@@ -92,16 +93,16 @@
  private:
   jlong  _entry_time;
   jlong  _exit_time;
-  char*  _name;
+  const char*  _name;
 
  public:
   jlong entry_time()              { return _entry_time; }
   jlong exit_time()               { return _exit_time; }
-  const char* name() const        { return (const char*)_name; }
+  const char* name() const        { return _name; }
 
   void set_entry_time(jlong time) { _entry_time = time; }
   void set_exit_time(jlong time)  { _exit_time = time; }
-  void set_name(char* name)       { _name = name; }
+  void set_name(const char* name) { _name = name; }
 };
 
 #endif // SHARE_VM_GC_PARALLEL_GCTASKTHREAD_HPP
--- a/src/share/vm/runtime/globals.hpp	Thu Apr 06 18:00:50 2017 +0000
+++ b/src/share/vm/runtime/globals.hpp	Fri Apr 07 10:45:26 2017 +0200
@@ -1457,9 +1457,9 @@
           "Number of threads concurrent gc will use")                       \
           constraint(ConcGCThreadsConstraintFunc,AfterErgo)                 \
                                                                             \
-  product(uintx, GCTaskTimeStampEntries, 200,                               \
+  product(uint, GCTaskTimeStampEntries, 200,                                \
           "Number of time stamp entries per gc worker thread")              \
-          range(1, max_uintx)                                               \
+          range(1, max_jint)                                                \
                                                                             \
   product(bool, AlwaysTenure, false,                                        \
           "Always tenure objects in eden (ParallelGC only)")                \
--- a/test/gc/parallel/TestPrintGCDetailsVerbose.java	Thu Apr 06 18:00:50 2017 +0000
+++ b/test/gc/parallel/TestPrintGCDetailsVerbose.java	Fri Apr 07 10:45:26 2017 +0200
@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2015, 2016, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2015, 2017, Oracle and/or its affiliates. All rights reserved.
  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
  *
  * This code is free software; you can redistribute it and/or modify it
@@ -23,12 +23,13 @@
 
 /*
  * @test TestPrintGCDetailsVerbose
- * @bug 8016740
+ * @bug 8016740 8177963
  * @summary Tests that jvm with maximally verbose GC logging does not crash when ParOldGC has no memory
  * @key gc
  * @requires vm.gc.Parallel
  * @modules java.base/jdk.internal.misc
  * @run main/othervm -Xmx50m -XX:+UseParallelGC -Xlog:gc*=trace TestPrintGCDetailsVerbose
+ * @run main/othervm -Xmx50m -XX:+UseParallelGC -XX:GCTaskTimeStampEntries=1 -Xlog:gc*=trace TestPrintGCDetailsVerbose
  */
 public class TestPrintGCDetailsVerbose {
 
--- a/test/native/runtime/test_globals.cpp	Thu Apr 06 18:00:50 2017 +0000
+++ b/test/native/runtime/test_globals.cpp	Fri Apr 07 10:45:26 2017 +0200
@@ -53,7 +53,7 @@
 }
 
 TEST_VM(FlagGuard, uintx_flag) {
-  TEST_FLAG(GCTaskTimeStampEntries, uintx, 1337);
+  TEST_FLAG(GCTaskTimeStampEntries, uint, 1337);
 }
 
 TEST_VM(FlagGuard, size_t_flag) {