G1 garbage collection Ext Root Scanning time increases due to Class.forName (Problem, Solution, and Patch)

[Thomas Schatzl]

On Thu, 2013-07-11 at 09:41 +0200, Thomas Schatzl wrote:
> Hi,
> 
>  first, let me say that I have not been involved in Ashley's discussion
> with John, so these are only observations. Maybe other gc people know
> more.
> 
> On Thu, 2013-07-11 at 16:42 +1000, David Holmes wrote:
> > Hi Ashley,
> > 
> > Is this Dictionary the systemDictionary in the VM or something to do 
> 
> In this test program, the number of entries in the system dictionary
> (SystemDictionary::number_of_classes()) grows steadily when using
> Class.forName() when looking up "java.util.HashMap" in a loop; when
> using the URLClassLoader instance to look up the same class, the size of

i.e. the loadClass() method.

> the system dictionary stays constant.

Fyi, maybe it helps: adding some code to
SystemDictionary::resolve_instance_class_or_null() indicates that when
using Class.forName() the loader_data (ClassLoaderData) is different
every time the code is executed, changing the hash code for the class.

Here are my changes:

Klass* SystemDictionary::resolve_instance_class_or_null(Symbol* name,
  Handle class_loader, Handle protection_domain, TRAPS) {
  assert(name != NULL && !FieldType::is_array(name) &&
         !FieldType::is_obj(name), "invalid class name");

  TracingTime class_load_start_time = Tracing::time();

  { ResourceMark rm;
gclog_or_tty->print("1 cl %s name %s\n", class_loader() != NULL ?
class_loader()->klass()->external_name() : "n/a", name->as_C_string());
   }
  // UseNewReflection
  // Fix for 4474172; see evaluation for more details
  class_loader = Handle(THREAD,
java_lang_ClassLoader::non_reflection_class_loader(class_loader()));
  ClassLoaderData *loader_data = register_loader(class_loader,
CHECK_NULL);
  { ResourceMark rm;
gclog_or_tty->print("2 cl %s "PTR_FORMAT" name %s\n", class_loader() !=
NULL ? class_loader()->klass()->external_name() : "n/a", loader_data,
name->as_C_string());
   }

prints

1 cl java.net.URLClassLoader name java/util/HashMap
2 cl java.net.URLClassLoader 0x00007f6851a5f200 name java/util/HashMap
1 cl n/a name java/util/HashMap
2 cl n/a 0x00007f6850221a60 name java/util/HashMap
adding java.util.HashMap class_loader java.net.URLClassLoader (index
520, hash 2143411148)

(the last line is some code that prints d_index and d_hash just before
dictionary()->add_klass() in SystemDictionary::update_dictionary())

for the Class.forName() path, and only

1 cl n/a name java/util/HashMap
2 cl n/a 0x00007f8ba8221a60 name java/util/HashMap

when using .loadClass().

Not sure if it helps, or there is a problem at all.

> Only a full gc "fixes" the problem.
> 
> > with G1? If there is an issue with the VM's use of the systemDictionary 
> > then it needs to be fixed in the VM. If there is an issue in G1 then it 
> > needs to be fixed in G1. A change to the Java-level behaviour of 
> > Class.forName needs to pass extreme scrutiny and as Ioi points out it is 
> > not appropriate for forName to assume how a ClassLoader will load a 
> > class - it must defer to the classloader to do it. So the patch is not 
> > acceptable.
> > 
> > What exactly is G1 reporting and why do you think it is wrong? (I have 
> > no idea what "Ext root scanning" means.)
> 
> Ext root scanning = "External root scanning" (I think :) time, i.e. an
> estimate for the time finding the roots and determining whether they
> should be changed take.

... whether further processing is needed.

Thomas