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

[Ioi Lam]

|While looking at this, I found a small optimization opportunity:

     void Dictionary::oops_do(OopClosure* f) {
       for (int index = 0; index < table_size(); index++) {
         for (DictionaryEntry* probe = bucket(index);
                               probe != NULL && probe->pd_set() != NULL;
                               probe = probe->next()) {
           probe->protection_domain_set_oops_do(f);
         }
       }
     }

We can sort each bucket so that all the classes that do NOT have a
protection domain are placed at the end of the list, so we can skip them
easily. However, this won't save too much time, as the GC bottleneck
(at least with the original test case) seems to be here:

     void ClassLoaderData::oops_do(OopClosure* f, KlassClosure* 
klass_closure,
                                   bool must_claim) {
       if (must_claim && !claim()) {
         return;
       }

       f->do_oop(&_class_loader);
       _dependencies.oops_do(f);
       _handles->oops_do(f);
       if (klass_closure != NULL) {
         classes_do(klass_closure);
       }
     }

||as well as in SystemDictionary::do_unloading().

- Ioi

|
On 07/11/2013 11:01 AM, Ioi Lam wrote:
> |Thomas, thanks for the pointers!
>
> Here's what I found. ||In the original test code, if you do this:
>
>     urlClassLoader.loadClass("java.util.HashMap");
>
> the urlClassLoader always delegates to the parent loader (the app class
> loader) first, and the app class loader always delegates to its parent
> loader (the boot class loader) first, this means the function
> |
>     SystemDictionary::resolve_instance_class_or_null()
>
> will always be called with (class_loader==boot_class_loader) first, which
> will succeed to find the class. This means resolve_instance_class_or_null()
> will never be called with (class_loader==|urlClassLoader), and this will
> never|create a new ClassLoaderData structure for it.
>
> However, if you do this
>
> |     Class.forName(|||"java.util.HashMap"|, false, urlClassLoader);
>
> then||resolve_instance_class_or_null() will always be called with||
> (class_loader==|urlClassLoader), and thus will create a new|ClassLoaderData
> for every new instance of|||urlClassLoader.
> ||
> I modified the test so that the requested class cannot be found in the
> parent loaders:
>
> ------------------------------------------------------------------
> import java.net.URL;
> import java.io.File;
> import java.net.URLClassLoader;
> import sun.net.www.ParseUtil;
>
> /*
>   * javac G1Checker2.java && mkdir -p foo && mv FooFoo.class foo/
>   *
>   * java -cp . G1Checker2
>   * java -cp . G1Checker2 classloader
>   *
>   * java -cp . -XX:+PrintGCDetails -XX:+UseG1GC G1Checker2
>   * java -cp . -XX:+PrintGCDetails -XX:+UseG1GC G1Checker2 classloader
>   */
> public class G1Checker2 {
>    public static void main(String[] args) throws Exception {
>      boolean classLoader = false;
>      if (args.length > 0) {
>        classLoader = "classloader".equals(args[0]);
>      }
>      String klassPath = "FooFoo";
>      ClassLoader loader = G1Checker.class.getClassLoader();
>
>      //loading a class referenced in the parent url loader
>      Class<?> theKlass;
>      while (true) {
>        File file = new File("foo");
>        file = file.getCanonicalFile();
>        URL urls[] = new URL[1];
>        urls[0] = ParseUtil.fileToEncodedURL(file);
>        URLClassLoader urlClassLoader = new URLClassLoader(urls, loader);
>          
>        if (classLoader) {
>          theKlass = urlClassLoader.loadClass(klassPath);
>        } else {
>          //loading it this way creates lots of references in the dictionary
>          theKlass = Class.forName(klassPath, false, urlClassLoader);
>        }
>        theKlass.toString();
>        //System.out.println("Loader = " + theKlass.getClassLoader());
>      }
>    }
> }
>
> class FooFoo {}
> -------------------------------------------------------------------
> With this modification, the "FooFoo" class is always loaded by the
> urlClassLoader in both cases. The G1 log shows comparable collection
> time in both cases.
>
> So, my conclusion is, the behavior observed in the original test
> (G1Checker.java) is neither a bug in GC or class loading.
> It's expected behavior.
>
> Hence, I have a question for Ashley -- in your use cases, do you create
> a lot of ClassLoader instances, but each of these instances always load all
> classes using their parent class loaders? (E.g., you have URLClassLoader with
> an empty URL[], as in your original test program). If so, what's the
> reason for doing it this way?
>
> Thanks
> - Ioi
>
>
> On 07/11/2013 01:53 AM, Thomas Schatzl wrote:
>> 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
>>
>>
>

-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://mail.openjdk.java.net/pipermail/hotspot-runtime-dev/attachments/20130711/fb5bd72a/attachment-0001.html