A severe performance regression was noticed when migrating an application from JDK 8 to JDK 14. This application runs lots of JS scripts under Nashorn in multiple threads.

The problem was narrowed down to ResolvedMethodTable. async-profiler showed that all worker threads were busy almost all time inside java_lang_invoke_ResolvedMethodName::find_resolved_method (see attached profile.svg).

ANALYSIS

With -Xlog:membername*=trace, JVM log was full of messages like

ResolvedMethod entry added for java.lang.invoke.LambdaForm$MH/0x00000017c7112440.invoke(Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object;
ResolvedMethod entry added for java.lang.invoke.LambdaForm$MH/0x00000017c70c9840.invoke(Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object;
ResolvedMethod entry added for java.lang.invoke.LambdaForm$MH/0x00000017c7136840.invoke(Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object;
ResolvedMethod entry added for java.lang.invoke.LambdaForm$MH/0x00000017c70be440.invoke(Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object;
ResolvedMethod entry added for java.lang.invoke.LambdaForm$MH/0x00000017c710bc40.invoke(Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object;
ResolvedMethod entry added for java.lang.invoke.LambdaForm$MH/0x00000017c7074840.invoke(Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object;
ResolvedMethod entry added for java.lang.invoke.LambdaForm$MH/0x00000017c7064840.invoke(Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object;

It is also remarkable that resizing table from 16384 to 32768 buckets took 6 minutes, and during this time the JVM did not respond at all.

[6.718s][debug][membername,table,perf] Grow, 0.0016585 secs
[6.718s][info ][membername,table     ] Grown to size:2048

[280.415s][debug][membername,table,perf] Grow, 0.0034216 secs
[280.415s][info ][membername,table     ] Grown to size:4096

[665.700s][debug][membername,table,perf] Grow, 0.0132153 secs
[665.700s][info ][membername,table     ] Grown to size:8192

[909.242s][debug][membername,table,perf] Grow, 1.3430992 secs
[909.242s][info ][membername,table     ] Grown to size:16384

[1781.645s][debug][membername,table,perf] Grow, 396.2095231 secs
[1781.668s][info ][membername,table     ] Grown to size:32768

I made a simple program that demonstrates the problem. See attached SlowMethodHandles.java

On JDK 8, this program easily creates 1 million MethodHandles, while on JDK 14 it almost dies after 30K handles.

The reason is the way how ResolvedMethodTable computes Method hashes:

unsigned int method_hash(const Method* method) {
  unsigned int name_hash = method->name()->identity_hash();
  unsigned int signature_hash = method->signature()->identity_hash();
  return name_hash ^ signature_hash;
}

Obviously, for the above invoke() methods of generated LambdaForms, all hashes are the same, since all methods have the same name and the same signature.

SOLUTION

method_hash() in resolvedMethodTable.cpp needs to be modified to take the holder class into account.

It's worth mentioning that Method::log_touched() also calculates Method hash, but includes the class:

  unsigned int hash = my_class->identity_hash() +
                      my_name->identity_hash() +
                      my_sig->identity_hash();

To fix the issue, I rewrote method_hash() as shown below, and the application became fast again.

unsigned int method_hash(const Method* method) {
  unsigned int hash = method->klass_name()->identity_hash();
  hash = (hash * 31) ^ method->name()->identity_hash();
  hash = (hash * 31) ^ method->signature()->identity_hash();
  return hash;
}