8216041: [Event Request] - Deoptimization

Reviewed-by: iignatyev, vlivanov, egahlin

src/hotspot/share/code/codeBlob.hpp

@@ -147,6 +147,7 @@ public:
   inline bool is_compiled_by_c2() const    { return _type == compiler_c2; };
   inline bool is_compiled_by_jvmci() const { return _type == compiler_jvmci; };
   const char* compiler_name() const;
+  CompilerType compiler_type() const { return _type; }
 
   // Casting
   nmethod* as_nmethod_or_null()                { return is_nmethod() ? (nmethod*) this : NULL; }

src/hotspot/share/compiler/compileBroker.cpp

@@ -2019,8 +2019,10 @@ void CompileBroker::post_compile(CompilerThread* thread, CompileTask* task, bool
 static void post_compilation_event(EventCompilation* event, CompileTask* task) {
   assert(event != NULL, "invariant");
   assert(event->should_commit(), "invariant");
-  event->set_method(task->method());
+  assert(task != NULL, "invariant");
   event->set_compileId(task->compile_id());
+  event->set_compiler(task->compiler()->type());
+  event->set_method(task->method());
   event->set_compileLevel(task->comp_level());
   event->set_succeded(task->is_success());
   event->set_isOsr(task->osr_bci() != CompileBroker::standard_entry_bci);

src/hotspot/share/jfr/metadata/metadata.xml

@@ -465,8 +465,9 @@
   </Event>
 
   <Event name="Compilation" category="Java Virtual Machine, Compiler" label="Compilation" thread="true">
-    <Field type="Method" name="method" label="Java Method" />
     <Field type="uint" name="compileId" label="Compilation Identifier" relation="CompileId" />
+    <Field type="CompilerType" name="compiler" label="Compiler" />
+    <Field type="Method" name="method" label="Method" />
     <Field type="ushort" name="compileLevel" label="Compilation Level" />
     <Field type="boolean" name="succeded" label="Succeeded" />
     <Field type="boolean" name="isOsr" label="On Stack Replacement" />
@@ -497,7 +498,7 @@
     <Field type="CalleeMethod" name="callee" struct="true" label="Callee Method" />
     <Field type="boolean" name="succeeded" label="Succeeded" />
     <Field type="string" name="message" label="Message" />
-    <Field type="int" name="bci" label="Byte Code Index" />
+    <Field type="int" name="bci" label="Bytecode Index" />
   </Event>
 
   <Event name="SweepCodeCache" category="Java Virtual Machine, Code Sweeper" label="Sweep Code Cache" thread="true" >
@@ -519,6 +520,17 @@
     <Field type="int" name="fullCount" label="Full Count" />
   </Event>
 
+  <Event name="Deoptimization" category="Java Virtual Machine, Compiler" label="Deoptimization" thread="true" stackTrace="true" startTime="false">
+    <Field type="uint" name="compileId" label="Compilation Identifier" relation="CompileId" />
+    <Field type="CompilerType" name="compiler" label="Compiler" />
+    <Field type="Method" name="method" label="Method" />
+    <Field type="int" name="lineNumber" label="Line Number" />
+    <Field type="int" name="bci" label="Bytecode Index" />
+    <Field type="Bytecode" name="instruction" label="Instruction" />
+    <Field type="DeoptimizationReason" name="reason" label="Reason"/>
+    <Field type="DeoptimizationAction" name="action" label="Action"/>
+  </Event>
+
   <Event name="SafepointBegin" category="Java Virtual Machine, Runtime, Safepoint" label="Safepoint Begin" description="Safepointing begin" thread="true">
     <Field type="ulong" name="safepointId" label="Safepoint Identifier" relation="SafepointId" />
     <Field type="int" name="totalThreadCount" label="Total Threads" description="The total number of threads at the start of safe point" />
@@ -1041,6 +1053,22 @@
     <Field type="ulong" contentType="bytes" name="size" label="Size Written" />
   </Event>
 
+  <Type name="DeoptimizationReason" label="Deoptimization Reason">
+    <Field type="string" name="reason" label="Reason" />
+  </Type>
+
+  <Type name="DeoptimizationAction" label="Deoptimization Action">
+    <Field type="string" name="action" label="Action" />
+  </Type>
+
+  <Type name="Bytecode" label="Bytecode Instruction">
+    <Field type="string" name="bytecode" label="Instruction" />
+  </Type>
+
+  <Type name="CompilerType" label="Compiler Type">
+    <Field type="string" name="compiler" label="Compiler" />
+  </Type>
+
   <Type name="ZStatisticsCounterType" label="Z Statistics Counter">
     <Field type="string" name="counter" label="Counter" />
   </Type>

src/hotspot/share/jfr/recorder/checkpoint/types/jfrType.cpp

@@ -26,6 +26,7 @@
 #include "classfile/javaClasses.inline.hpp"
 #include "code/codeBlob.hpp"
 #include "code/codeCache.hpp"
+#include "compiler/compilerDefinitions.hpp"
 #include "gc/shared/gcCause.hpp"
 #include "gc/shared/gcName.hpp"
 #include "gc/shared/gcTrace.hpp"
@@ -293,3 +294,21 @@ void JfrThreadConstant::serialize(JfrCheckpointWriter& writer) {
   writer.write((traceid)0); // java thread id
   writer.write((traceid)0); // java thread group
 }
+
+void BytecodeConstant::serialize(JfrCheckpointWriter& writer) {
+  static const u4 nof_entries = Bytecodes::number_of_codes;
+  writer.write_count(nof_entries);
+  for (u4 i = 0; i < nof_entries; ++i) {
+    writer.write_key(i);
+    writer.write(Bytecodes::name((Bytecodes::Code)i));
+  }
+}
+
+void CompilerTypeConstant::serialize(JfrCheckpointWriter& writer) {
+  static const u4 nof_entries = compiler_number_of_types;
+  writer.write_count(nof_entries);
+  for (u4 i = 0; i < nof_entries; ++i) {
+    writer.write_key(i);
+    writer.write(compilertype2name((CompilerType)i));
+  }
+}

src/hotspot/share/jfr/recorder/checkpoint/types/jfrType.hpp

@@ -115,4 +115,14 @@ class JfrThreadConstant : public JfrSerializer {
   void serialize(JfrCheckpointWriter& writer);
 };
 
+class BytecodeConstant : public JfrSerializer {
+ public:
+  void serialize(JfrCheckpointWriter& writer);
+};
+
+class CompilerTypeConstant : public JfrSerializer {
+ public:
+  void serialize(JfrCheckpointWriter& writer);
+};
+
 #endif // SHARE_JFR_RECORDER_CHECKPOINT_TYPES_JFRTYPE_HPP

src/hotspot/share/jfr/recorder/checkpoint/types/jfrTypeManager.cpp

@@ -222,6 +222,8 @@ bool JfrTypeManager::initialize() {
   register_static_type(TYPE_CODEBLOBTYPE, true, new CodeBlobTypeConstant());
   register_static_type(TYPE_VMOPERATIONTYPE, true, new VMOperationTypeConstant());
   register_static_type(TYPE_THREADSTATE, true, new ThreadStateConstant());
+  register_static_type(TYPE_BYTECODE, true, new BytecodeConstant());
+  register_static_type(TYPE_COMPILERTYPE, true, new CompilerTypeConstant());
   return true;
 }
 

src/hotspot/share/runtime/deoptimization.cpp

@@ -56,9 +56,9 @@
 #include "runtime/fieldDescriptor.hpp"
 #include "runtime/fieldDescriptor.inline.hpp"
 #include "runtime/frame.inline.hpp"
-#include "runtime/jniHandles.inline.hpp"
 #include "runtime/handles.inline.hpp"
 #include "runtime/interfaceSupport.inline.hpp"
+#include "runtime/jniHandles.inline.hpp"
 #include "runtime/safepointVerifiers.hpp"
 #include "runtime/sharedRuntime.hpp"
 #include "runtime/signature.hpp"
@@ -69,9 +69,13 @@
 #include "runtime/vframeArray.hpp"
 #include "runtime/vframe_hp.hpp"
 #include "utilities/events.hpp"
+#include "utilities/macros.hpp"
 #include "utilities/preserveException.hpp"
 #include "utilities/xmlstream.hpp"
-
+#if INCLUDE_JFR
+#include "jfr/jfrEvents.hpp"
+#include "jfr/metadata/jfrSerializer.hpp"
+#endif
 
 bool DeoptimizationMarker::_is_active = false;
 
@@ -1652,6 +1656,69 @@ void Deoptimization::load_class_by_index(const constantPoolHandle& constant_pool
   }
 }
 
+#if INCLUDE_JFR
+
+class DeoptReasonSerializer : public JfrSerializer {
+ public:
+  void serialize(JfrCheckpointWriter& writer) {
+    writer.write_count((u4)(Deoptimization::Reason_LIMIT + 1)); // + Reason::many (-1)
+    for (int i = -1; i < Deoptimization::Reason_LIMIT; ++i) {
+      writer.write_key((u8)i);
+      writer.write(Deoptimization::trap_reason_name(i));
+    }
+  }
+};
+
+class DeoptActionSerializer : public JfrSerializer {
+ public:
+  void serialize(JfrCheckpointWriter& writer) {
+    static const u4 nof_actions = Deoptimization::Action_LIMIT;
+    writer.write_count(nof_actions);
+    for (u4 i = 0; i < Deoptimization::Action_LIMIT; ++i) {
+      writer.write_key(i);
+      writer.write(Deoptimization::trap_action_name((int)i));
+    }
+  }
+};
+
+static void register_serializers() {
+  static int critical_section = 0;
+  if (1 == critical_section || Atomic::cmpxchg(&critical_section, 0, 1) == 1) {
+    return;
+  }
+  JfrSerializer::register_serializer(TYPE_DEOPTIMIZATIONREASON, true, new DeoptReasonSerializer());
+  JfrSerializer::register_serializer(TYPE_DEOPTIMIZATIONACTION, true, new DeoptActionSerializer());
+}
+
+static void post_deoptimization_event(CompiledMethod* nm,
+                                      const Method* method,
+                                      int trap_bci,
+                                      int instruction,
+                                      Deoptimization::DeoptReason reason,
+                                      Deoptimization::DeoptAction action) {
+  assert(nm != NULL, "invariant");
+  assert(method != NULL, "invariant");
+  if (EventDeoptimization::is_enabled()) {
+    static bool serializers_registered = false;
+    if (!serializers_registered) {
+      register_serializers();
+      serializers_registered = true;
+    }
+    EventDeoptimization event;
+    event.set_compileId(nm->compile_id());
+    event.set_compiler(nm->compiler_type());
+    event.set_method(method);
+    event.set_lineNumber(method->line_number_from_bci(trap_bci));
+    event.set_bci(trap_bci);
+    event.set_instruction(instruction);
+    event.set_reason(reason);
+    event.set_action(action);
+    event.commit();
+  }
+}
+
+#endif // INCLUDE_JFR
+
 JRT_ENTRY(void, Deoptimization::uncommon_trap_inner(JavaThread* thread, jint trap_request)) {
   HandleMark hm;
 
@@ -1746,6 +1813,8 @@ JRT_ENTRY(void, Deoptimization::uncommon_trap_inner(JavaThread* thread, jint tra
     MethodData* trap_mdo =
       get_method_data(thread, profiled_method, create_if_missing);
 
+    JFR_ONLY(post_deoptimization_event(nm, trap_method(), trap_bci, trap_bc, reason, action);)
+
     // Log a message
     Events::log_deopt_message(thread, "Uncommon trap: reason=%s action=%s pc=" INTPTR_FORMAT " method=%s @ %d %s",
                               trap_reason_name(reason), trap_action_name(action), p2i(fr.pc()),

src/jdk.jfr/share/conf/jfr/default.jfc

@@ -728,6 +728,11 @@
       <setting name="threshold">0 ms</setting>
     </event>
 
+    <event name="jdk.Deoptimization">
+      <setting name="enabled">true</setting>
+      <setting name="stackTrace">false</setting>
+    </event>
+
 
 
 

src/jdk.jfr/share/conf/jfr/profile.jfc

@@ -728,6 +728,10 @@
       <setting name="threshold">0 ms</setting>
     </event>
 
+    <event name="jdk.Deoptimization">
+      <setting name="enabled">true</setting>
+      <setting name="stackTrace">true</setting>
+    </event>
 
 
 

test/jdk/jdk/jfr/event/compiler/TestDeoptimization.java

@@ -0,0 +1,124 @@
+/*
+ * 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.  Oracle designates this
+ * particular file as subject to the "Classpath" exception as provided
+ * by Oracle in the LICENSE file that accompanied this code.
+ *
+ * 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.
+ */
+
+package jdk.jfr.event.compiler;
+
+import java.util.List;
+import java.util.stream.Collectors;
+
+import jdk.jfr.Recording;
+import jdk.jfr.consumer.RecordedEvent;
+import jdk.test.lib.Asserts;
+import jdk.test.lib.jfr.EventNames;
+import jdk.test.lib.jfr.Events;
+
+//    THIS TEST IS LINE NUMBER SENSITIVE
+
+// Careful if moving this class or method somewhere since verifyDeoptimizationEventFields asserts the linenumber
+class Dummy {
+    static void dummyMethod(boolean b) {
+        if (b) {
+            return;
+        }
+    }
+}
+
+/**
+ * @test
+ * @key jfr
+ * @summary sanity test for Deoptimization event, depends on Compilation event
+ * @requires vm.hasJFR
+ * @requires vm.compMode != "Xint"
+ * @requires vm.flavor == "server" & (vm.opt.TieredStopAtLevel == 4 | vm.opt.TieredStopAtLevel == null)
+ * @library /test/lib
+ * @run main/othervm -XX:-BackgroundCompilation jdk.jfr.event.compiler.TestDeoptimization
+ */
+public class TestDeoptimization {
+    private final static String TYPE_NAME = Dummy.class.getName().replace(".", "/");
+    private final static String METHOD_NAME = "dummyMethod";
+    private static final String METHOD_DESCRIPTOR = "(Z)V";
+    private static final String COMPILER = "c2";
+
+    public static void main(String[] args) throws Throwable {
+        new TestDeoptimization().doTest();
+    }
+
+    public void doTest() throws Throwable {
+        Recording recording = new Recording();
+        recording.enable(EventNames.Deoptimization);
+        recording.enable(EventNames.Compilation);
+        recording.start();
+
+        long start = System.currentTimeMillis();
+        // compile dummyMethod
+        for (int i = 0; i < 20000; i++) {
+            Dummy.dummyMethod(false);
+        }
+        // provoke deoptimization by executing the uncommon trap in dummyMethod
+        Dummy.dummyMethod(true);
+        System.out.println("Time to load, compile and deoptimize dummyMethod: " + (System.currentTimeMillis() - start));
+        recording.stop();
+
+        List<RecordedEvent> events = Events.fromRecording(recording);
+        Events.hasEvents(events);
+
+        // get compile ids for all compilations of dummyMethod
+        List<Integer> compileIds = events.stream()
+                .filter(e -> e.getEventType().getName().equals(EventNames.Compilation))
+                .filter(TestDeoptimization::isForDummyMethod)
+                .map(e -> Events.assertField(e, "compileId").<Integer>getValue())
+                .collect(Collectors.toList());
+        Asserts.assertFalse(compileIds.isEmpty(),
+                "couldn't find any " + EventNames.Compilation + " for " + METHOD_NAME);
+
+        // get all deoptimization events associated with the compile ids
+        List<RecordedEvent> deoptEventsForCompileIds = events.stream()
+              .filter(e -> e.getEventType().getName().equals(EventNames.Deoptimization))
+              .filter(e -> compileIds.contains(Events.assertField(e, "compileId").<Integer>getValue()))
+              .collect(Collectors.toList());
+        Asserts.assertFalse(deoptEventsForCompileIds.isEmpty(),
+                "couldn't find any " + EventNames.Deoptimization + " for ids : " + compileIds);
+
+        // verify deoptimization event fields
+        deoptEventsForCompileIds.forEach(this::verifyDeoptimizationEventFields);
+    }
+
+    static boolean isForDummyMethod(RecordedEvent e) {
+        return TYPE_NAME.equals(Events.assertField(e, "method.type.name").getValue())
+                && METHOD_NAME.equals(Events.assertField(e, "method.name").getValue())
+                && METHOD_DESCRIPTOR.equals(Events.assertField(e, "method.descriptor").getValue());
+    }
+
+    private void verifyDeoptimizationEventFields(RecordedEvent event) {
+        Events.assertEventThread(event);
+        Events.assertField(event, "compileId").atLeast(0);
+        Events.assertField(event, "compiler").equal(COMPILER);
+        Events.assertField(event, "lineNumber").equal(42);
+        Events.assertField(event, "bci").equal(1);
+        Events.assertField(event, "instruction").equal("ifeq");
+        Events.assertField(event, "action").notEmpty().equal("reinterpret");
+        Events.assertField(event, "reason").notEmpty().equal("unstable_if");
+    }
+}

test/lib/jdk/test/lib/jfr/EventNames.java

@@ -153,6 +153,7 @@ public class EventNames {
     public final static String CodeCacheFull = PREFIX + "CodeCacheFull";
     public final static String ObjectAllocationInNewTLAB = PREFIX + "ObjectAllocationInNewTLAB";
     public final static String ObjectAllocationOutsideTLAB = PREFIX + "ObjectAllocationOutsideTLAB";
+    public final static String Deoptimization = PREFIX + "Deoptimization";
 
     // OS
     public final static String OSInformation = PREFIX + "OSInformation";