8224600: Provide VM.events command

Reviewed-by: minqi, dholmes, mbaesken, clanger

src/hotspot/share/compiler/compileBroker.cpp

@@ -187,7 +187,7 @@ CompileQueue* CompileBroker::_c1_compile_queue     = NULL;
 
 class CompilationLog : public StringEventLog {
  public:
-  CompilationLog() : StringEventLog("Compilation events") {
+  CompilationLog() : StringEventLog("Compilation events", "jit") {
   }
 
   void log_compile(JavaThread* thread, CompileTask* task) {

src/hotspot/share/gc/shared/collectedHeap.hpp

@@ -73,7 +73,7 @@ class GCHeapLog : public EventLogBase<GCMessage> {
   void log_heap(CollectedHeap* heap, bool before);
 
  public:
-  GCHeapLog() : EventLogBase<GCMessage>("GC Heap History") {}
+  GCHeapLog() : EventLogBase<GCMessage>("GC Heap History", "gc") {}
 
   void log_heap_before(CollectedHeap* heap) {
     log_heap(heap, true);

src/hotspot/share/services/diagnosticCommand.cpp

@@ -1,5 +1,5 @@
 /*
- * Copyright (c) 2011, 2018, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2011, 2019, 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
@@ -48,6 +48,7 @@
 #include "services/management.hpp"
 #include "services/writeableFlags.hpp"
 #include "utilities/debug.hpp"
+#include "utilities/events.hpp"
 #include "utilities/formatBuffer.hpp"
 #include "utilities/macros.hpp"
 
@@ -95,6 +96,7 @@ void DCmdRegistrant::register_dcmds(){
   DCmdFactory::register_DCmdFactory(new DCmdFactoryImpl<SymboltableDCmd>(full_export, true, false));
   DCmdFactory::register_DCmdFactory(new DCmdFactoryImpl<StringtableDCmd>(full_export, true, false));
   DCmdFactory::register_DCmdFactory(new DCmdFactoryImpl<metaspace::MetaspaceDCmd>(full_export, true, false));
+  DCmdFactory::register_DCmdFactory(new DCmdFactoryImpl<EventLogDCmd>(full_export, true, false));
 #if INCLUDE_JVMTI // Both JVMTI and SERVICES have to be enabled to have this dcmd
   DCmdFactory::register_DCmdFactory(new DCmdFactoryImpl<JVMTIAgentLoadDCmd>(full_export, true, false));
 #endif // INCLUDE_JVMTI
@@ -965,6 +967,45 @@ int CodeHeapAnalyticsDCmd::num_arguments() {
 }
 //---<  END  >--- CodeHeap State Analytics.
 
+EventLogDCmd::EventLogDCmd(outputStream* output, bool heap) :
+  DCmdWithParser(output, heap),
+  _log("log", "Name of log to be printed. If omitted, all logs are printed.", "STRING", false, NULL),
+  _max("max", "Maximum number of events to be printed (newest first). If omitted, all events are printed.", "STRING", false, NULL)
+{
+  _dcmdparser.add_dcmd_option(&_log);
+  _dcmdparser.add_dcmd_option(&_max);
+}
+
+void EventLogDCmd::execute(DCmdSource source, TRAPS) {
+  const char* max_value = _max.value();
+  long max = -1;
+  if (max_value != NULL) {
+    char* endptr = NULL;
+    max = ::strtol(max_value, &endptr, 10);
+    if (max == 0 && max_value == endptr) {
+      output()->print_cr("Invalid max option: \"%s\".", max_value);
+      return;
+    }
+  }
+  const char* log_name = _log.value();
+  if (log_name != NULL) {
+    Events::print_one(output(), log_name, max);
+  } else {
+    Events::print_all(output(), max);
+  }
+}
+
+int EventLogDCmd::num_arguments() {
+  ResourceMark rm;
+  EventLogDCmd* dcmd = new EventLogDCmd(NULL, false);
+  if (dcmd != NULL) {
+    DCmdMark mark(dcmd);
+    return dcmd->_dcmdparser.num_arguments();
+  } else {
+    return 0;
+  }
+}
+
 void CompilerDirectivesPrintDCmd::execute(DCmdSource source, TRAPS) {
   DirectivesStack::print(output());
 }

src/hotspot/share/services/diagnosticCommand.hpp

@@ -888,4 +888,28 @@ public:
 };
 #endif // INCLUDE_JVMTI
 
+class EventLogDCmd : public DCmdWithParser {
+protected:
+  DCmdArgument<char*> _log;
+  DCmdArgument<char*> _max;
+public:
+  EventLogDCmd(outputStream* output, bool heap);
+  static const char* name() {
+    return "VM.events";
+  }
+  static const char* description() {
+    return "Print VM event logs";
+  }
+  static const char* impact() {
+    return "Low: Depends on event log size. ";
+  }
+  static const JavaPermission permission() {
+    JavaPermission p = {"java.lang.management.ManagementPermission",
+                        "monitor", NULL};
+    return p;
+  }
+  static int num_arguments();
+  virtual void execute(DCmdSource source, TRAPS);
+};
+
 #endif // SHARE_SERVICES_DIAGNOSTICCOMMAND_HPP

src/hotspot/share/utilities/events.cpp

@@ -51,26 +51,51 @@ EventLog::EventLog() {
 }
 
 // For each registered event logger, print out the current contents of
-// the buffer.  This is normally called when the JVM is crashing.
-void Events::print_all(outputStream* out) {
+// the buffer.
+void Events::print_all(outputStream* out, int max) {
   EventLog* log = _logs;
   while (log != NULL) {
-    log->print_log_on(out);
+    log->print_log_on(out, max);
     log = log->next();
   }
 }
 
+// Print a single event log specified by name.
+void Events::print_one(outputStream* out, const char* log_name, int max) {
+  EventLog* log = _logs;
+  int num_printed = 0;
+  while (log != NULL) {
+    if (log->matches_name_or_handle(log_name)) {
+      log->print_log_on(out, max);
+      num_printed ++;
+    }
+    log = log->next();
+  }
+  // Write a short error note if no name matched.
+  if (num_printed == 0) {
+    out->print_cr("The name \"%s\" did not match any known event log. "
+                  "Valid event log names are:", log_name);
+    EventLog* log = _logs;
+    while (log != NULL) {
+      log->print_names(out);
+      out->cr();
+      log = log->next();
+    }
+  }
+}
+
+
 void Events::print() {
   print_all(tty);
 }
 
 void Events::init() {
   if (LogEvents) {
-    _messages = new StringEventLog("Events");
-    _exceptions = new ExceptionsEventLog("Internal exceptions");
-    _redefinitions = new StringEventLog("Classes redefined");
-    _class_unloading = new UnloadingEventLog("Classes unloaded");
-    _deopt_messages = new StringEventLog("Deoptimization events");
+    _messages = new StringEventLog("Events", "events");
+    _exceptions = new ExceptionsEventLog("Internal exceptions", "exc");
+    _redefinitions = new StringEventLog("Classes redefined", "redef");
+    _class_unloading = new UnloadingEventLog("Classes unloaded", "unload");
+    _deopt_messages = new StringEventLog("Deoptimization events", "deopt");
   }
 }
 

src/hotspot/share/utilities/events.hpp

@@ -29,6 +29,8 @@
 #include "runtime/mutexLocker.hpp"
 #include "runtime/thread.hpp"
 #include "utilities/formatBuffer.hpp"
+#include "utilities/globalDefinitions.hpp"
+#include "utilities/ostream.hpp"
 #include "utilities/vmError.hpp"
 
 // Events and EventMark provide interfaces to log events taking place in the vm.
@@ -59,7 +61,15 @@ class EventLog : public CHeapObj<mtInternal> {
   // crashes.
   EventLog();
 
-  virtual void print_log_on(outputStream* out) = 0;
+  // Print log to output stream.
+  virtual void print_log_on(outputStream* out, int max = -1) = 0;
+
+  // Returns true if s matches either the log name or the log handle.
+  virtual bool matches_name_or_handle(const char* s) const = 0;
+
+  // Print log names (for help output of VM.events).
+  virtual void print_names(outputStream* out) const = 0;
+
 };
 
 
@@ -78,16 +88,21 @@ template <class T> class EventLogBase : public EventLog {
 
  protected:
   Mutex           _mutex;
+  // Name is printed out as a header.
   const char*     _name;
+  // Handle is a short specifier used to select this particular event log
+  // for printing (see VM.events command).
+  const char*     _handle;
   int             _length;
   int             _index;
   int             _count;
   EventRecord<T>* _records;
 
  public:
-  EventLogBase<T>(const char* name, int length = LogEventsBufferEntries):
+  EventLogBase<T>(const char* name, const char* handle, int length = LogEventsBufferEntries):
     _mutex(Mutex::event, name, false, Monitor::_safepoint_check_never),
     _name(name),
+    _handle(handle),
     _length(length),
     _index(0),
     _count(0) {
@@ -116,10 +131,16 @@ template <class T> class EventLogBase : public EventLog {
   }
 
   // Print the contents of the log
-  void print_log_on(outputStream* out);
+  void print_log_on(outputStream* out, int max = -1);
+
+  // Returns true if s matches either the log name or the log handle.
+  bool matches_name_or_handle(const char* s) const;
+
+  // Print log names (for help output of VM.events).
+  void print_names(outputStream* out) const;
 
  private:
-  void print_log_impl(outputStream* out);
+  void print_log_impl(outputStream* out, int max = -1);
 
   // Print a single element.  A templated implementation might need to
   // be declared by subclasses.
@@ -145,7 +166,8 @@ typedef FormatStringLogMessage<512> ExtendedStringLogMessage;
 template <size_t bufsz>
 class FormatStringEventLog : public EventLogBase< FormatStringLogMessage<bufsz> > {
  public:
-  FormatStringEventLog(const char* name, int count = LogEventsBufferEntries) : EventLogBase< FormatStringLogMessage<bufsz> >(name, count) {}
+  FormatStringEventLog(const char* name, const char* short_name, int count = LogEventsBufferEntries)
+   : EventLogBase< FormatStringLogMessage<bufsz> >(name, short_name, count) {}
 
   void logv(Thread* thread, const char* format, va_list ap) ATTRIBUTE_PRINTF(3, 0) {
     if (!this->should_log()) return;
@@ -173,7 +195,8 @@ class InstanceKlass;
 // Event log for class unloading events to materialize the class name in place in the log stream.
 class UnloadingEventLog : public EventLogBase<StringLogMessage> {
  public:
-  UnloadingEventLog(const char* name, int count = LogEventsBufferEntries) : EventLogBase<StringLogMessage>(name, count) {}
+  UnloadingEventLog(const char* name, const char* short_name, int count = LogEventsBufferEntries)
+   : EventLogBase<StringLogMessage>(name, short_name, count) {}
 
   void log(Thread* thread, InstanceKlass* ik);
 };
@@ -181,7 +204,8 @@ class UnloadingEventLog : public EventLogBase<StringLogMessage> {
 // Event log for exceptions
 class ExceptionsEventLog : public ExtendedStringEventLog {
  public:
-  ExceptionsEventLog(const char* name, int count = LogEventsBufferEntries) : ExtendedStringEventLog(name, count) {}
+  ExceptionsEventLog(const char* name, const char* short_name, int count = LogEventsBufferEntries)
+   : ExtendedStringEventLog(name, short_name, count) {}
 
   void log(Thread* thread, Handle h_exception, const char* message, const char* file, int line);
 };
@@ -209,7 +233,13 @@ class Events : AllStatic {
   // Class unloading events
   static UnloadingEventLog* _class_unloading;
  public:
-  static void print_all(outputStream* out);
+
+  // Print all event logs; limit number of events per event log to be printed with max
+  // (max == -1 prints all events).
+  static void print_all(outputStream* out, int max = -1);
+
+  // Print a single event log specified by name or handle.
+  static void print_one(outputStream* out, const char* log_name, int max = -1);
 
   // Dump all events to the tty
   static void print();
@@ -279,21 +309,31 @@ inline void Events::log_deopt_message(Thread* thread, const char* format, ...) {
   }
 }
 
-
 template <class T>
-inline void EventLogBase<T>::print_log_on(outputStream* out) {
+inline void EventLogBase<T>::print_log_on(outputStream* out, int max) {
   if (Thread::current_or_null() == NULL) {
     // Not yet attached? Don't try to use locking
-    print_log_impl(out);
+    print_log_impl(out, max);
   } else {
     MutexLocker ml(&_mutex, Mutex::_no_safepoint_check_flag);
-    print_log_impl(out);
+    print_log_impl(out, max);
   }
 }
 
+template <class T>
+inline bool EventLogBase<T>::matches_name_or_handle(const char* s) const {
+  return ::strcasecmp(s, _name) == 0 ||
+         ::strcasecmp(s, _handle) == 0;
+}
+
+template <class T>
+inline void EventLogBase<T>::print_names(outputStream* out) const {
+  out->print("\"%s\" : %s", _handle, _name);
+}
+
 // Dump the ring buffer entries that current have entries.
 template <class T>
-inline void EventLogBase<T>::print_log_impl(outputStream* out) {
+inline void EventLogBase<T>::print_log_impl(outputStream* out, int max) {
   out->print_cr("%s (%d events):", _name, _count);
   if (_count == 0) {
     out->print_cr("No events");
@@ -301,18 +341,36 @@ inline void EventLogBase<T>::print_log_impl(outputStream* out) {
     return;
   }
 
+  int printed = 0;
   if (_count < _length) {
     for (int i = 0; i < _count; i++) {
+      if (max > 0 && printed == max) {
+        break;
+      }
       print(out, _records[i]);
+      printed ++;
     }
   } else {
     for (int i = _index; i < _length; i++) {
+      if (max > 0 && printed == max) {
+        break;
+      }
       print(out, _records[i]);
+      printed ++;
     }
     for (int i = 0; i < _index; i++) {
+      if (max > 0 && printed == max) {
+        break;
+      }
       print(out, _records[i]);
+      printed ++;
     }
   }
+
+  if (printed == max) {
+    out->print_cr("...(skipped)");
+  }
+
   out->cr();
 }
 

test/hotspot/jtreg/serviceability/dcmd/vm/EventsTest.java

@@ -0,0 +1,69 @@
+/*
+ * Copyright (c) 2019, 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
+ * under the terms of the GNU General Public License version 2 only, as
+ * published by the Free Software Foundation.
+ *
+ * This code is distributed in the hope that it will be useful, but WITHOUT
+ * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
+ * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
+ * version 2 for more details (a copy is included in the LICENSE file that
+ * accompanied this code).
+ *
+ * You should have received a copy of the GNU General Public License version
+ * 2 along with this work; if not, write to the Free Software Foundation,
+ * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
+ *
+ * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
+ * or visit www.oracle.com if you need additional information or have any
+ * questions.
+ */
+
+import jdk.test.lib.dcmd.CommandExecutor;
+import jdk.test.lib.dcmd.JMXExecutor;
+import jdk.test.lib.process.OutputAnalyzer;
+import org.testng.annotations.Test;
+
+/*
+ * @test
+ * @summary Test of diagnostic command VM.events
+ * @library /test/lib
+ * @modules java.base/jdk.internal.misc
+ *          java.compiler
+ *          java.management
+ *          jdk.internal.jvmstat/sun.jvmstat.monitor
+ * @run testng  EventsTest
+ */
+public class EventsTest {
+
+    public void run_all(CommandExecutor executor) {
+        OutputAnalyzer output = executor.execute("VM.events");
+        // This tests for the output to contain the event log *names*. Those are always
+        // printed even if the corresponding event log is empty (e.g. "Classes redefined (0 events)")
+        output.shouldContain("Events");
+        output.shouldContain("Compilation");
+        output.shouldContain("GC");
+        output.shouldContain("Deoptimization");
+        output.shouldContain("Classes unloaded");
+    }
+
+    public void run_selected(CommandExecutor executor) {
+        OutputAnalyzer output = executor.execute("VM.events log=deopt");
+        // This tests for the output to contain the event log *names*. Those are always
+        // printed even if the corresponding event log is empty (e.g. "Classes redefined (0 events)")
+        output.shouldContain("Deoptimization");
+
+        output.shouldNotContain("Events");
+        output.shouldNotContain("Compilation");
+        output.shouldNotContain("GC");
+        output.shouldNotContain("Classes unloaded");
+    }
+
+    @Test
+    public void jmx() {
+        run_all(new JMXExecutor());
+        run_selected(new JMXExecutor());
+    }
+}