Uploaded image for project: 'JDK'
  1. JDK
  2. JDK-8306843

JVMTI tag map extremely slow after JDK-8292741

    XMLWordPrintable

Details

    • Bug
    • Resolution: Fixed
    • P3
    • 21
    • 20, 21
    • hotspot
    • b22
    • generic
    • generic

    Description

      ADDITIONAL SYSTEM INFORMATION :
      21-ea build 21-ea+19-1566

      A DESCRIPTION OF THE PROBLEM :
      JVMTI operations related to tags are unusably slow now. Some timing data for tagging and iterating 10_000_000 objects:

      19 build 19.0.2+7-44

      setTag: 1969 ms
      getTag: 743 ms
      iterate tagged: 437 ms
      iterate all: 499 ms

      20 build 20.0.1+9-29

      setTag: 2852 ms
      getTag: 1851 ms
      iterate tagged: 1496 ms
      iterate all: 1585 ms

      21-ea build 21-ea+19-1566

      setTag: 4135765 ms
      getTag: 4118573 ms
      iterate tagged: 9287657 ms
      iterate all: 9495863 ms

      JVMTI tag map already got up to 3 times slower in JDK 20, probably due to JDK-8256072.

      When reverting the JDK-8292741 changes, the timings are similar to JDK-20.

      A fast (optimally concurrent) tag map is extremely important for profilers and other kind of JVMTI agents.

      REGRESSION : Last worked in version 20.0.1

      STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
      With the attached sources and JAVA_HOME set to the JDK to be tested:

      g++ -shared -I$JAVA_HOME/include -I$JAVA_HOME/include/linux -fPIC TagMapTest.cpp -o libTagMapTest.so

      $JAVA_HOME/bin/javac TagMapTest.java

      LD_LIBRARY_PATH=. $JAVA_HOME/bin/java -agentlib:TagMapTest TagMapTest

      EXPECTED VERSUS ACTUAL BEHAVIOR :
      EXPECTED -
      Timings like in JDK 19 or at least JDK 20.
      ACTUAL -
      Extremely slow timings

      ---------- BEGIN SOURCE ----------
      TagMapTest.cpp -----------------------------------------------
      #include <jvmti.h>
      #include <cstdlib>
      #include <cstring>

      namespace {
          jlong nextTag = 1;
          jvmtiEnv *jvmti = nullptr;

          void checkJvmti(int code, const char* message) {
              if (code != JVMTI_ERROR_NONE) {
                  printf("Error %s: %d\n", message, code);
                  abort();
              }
          }

          jvmtiIterationControl JNICALL heapObjectCallback(jlong class_tag, jlong size, jlong* tag_ptr, void* user_data) {
              if (*tag_ptr == 0) {
                  *tag_ptr = nextTag++;
              }
              return JVMTI_ITERATION_CONTINUE;
          }
      }

      extern "C" JNIEXPORT void JNICALL Java_TagMapTest_setTag(JNIEnv* jni_env, jclass clazz, jobject object) {
          checkJvmti(jvmti->SetTag(object, nextTag++), "could not set tag");
      }

      extern "C" JNIEXPORT jlong JNICALL Java_TagMapTest_getTag(JNIEnv* jni_env, jclass clazz, jobject object) {
          jlong tag;
          checkJvmti(jvmti->GetTag(object, &tag), "could not get tag");
          return tag;
      }

      extern "C" JNIEXPORT void JNICALL Java_TagMapTest_iterate(JNIEnv* jni_env, jclass clazz, jboolean tagged) {
          checkJvmti(jvmti->IterateOverHeap(tagged ? JVMTI_HEAP_OBJECT_TAGGED : JVMTI_HEAP_OBJECT_EITHER, &heapObjectCallback, nullptr), "could not iterate");
      }

      extern "C" JNIEXPORT jint JNICALL Agent_OnLoad(JavaVM *vm, char *options, void *reserved) {
          if (vm->GetEnv(reinterpret_cast<void **>(&jvmti), JVMTI_VERSION) != JNI_OK || !jvmti) {
              printf("Could not initialize JVMTI\n");
              abort();
          }
          jvmtiCapabilities capabilities;
          memset(&capabilities, 0, sizeof(capabilities));
          capabilities.can_tag_objects = 1;
          checkJvmti(jvmti->AddCapabilities(&capabilities), "adding capabilities");
          printf("Loaded agent\n");
          fflush(stdout);
          return JVMTI_ERROR_NONE;
      }
      -------------------------------------------------
      TagMapTest.java -------------------------------
      import java.util.ArrayList;
      import java.util.List;
      import java.util.concurrent.TimeUnit;

      public class TagMapTest {
          private static final List<TagMapTest> items = new ArrayList<>();

          private static native void setTag(Object object);
          private static native long getTag(Object object);
          private static native void iterate(boolean tagged);

          public static void main(String[] args) {
              System.loadLibrary("TagMapTest");
              for (int i = 0; i < 10_000_000; i++) {
                  items.add(new TagMapTest());
              }

              long startTime = System.nanoTime();
              for (TagMapTest item : items) {
                  setTag(item);
              }
              System.out.println("setTag: " + TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - startTime) + " ms");

              startTime = System.nanoTime();
              for (TagMapTest item : items) {
                  getTag(item);
              }
              System.out.println("getTag: " + TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - startTime) + " ms");

              startTime = System.nanoTime();
              iterate(true);
              System.out.println("iterate tagged: " + TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - startTime) + " ms");

              startTime = System.nanoTime();
              iterate(false);
              System.out.println("iterate all: " + TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - startTime) + " ms");
          }
      }
      ---------------------------------------------
      ---------- END SOURCE ----------

      FREQUENCY : always


      Attachments

        Issue Links

          Activity

            People

              coleenp Coleen Phillimore
              webbuggrp Webbug Group
              Votes:
              0 Vote for this issue
              Watchers:
              6 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: