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

David Holmes david.holmes at oracle.com
Thu Jul 11 20:05:33 PDT 2013


Hi Ioi,

On 12/07/2013 4: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.

Thanks Ioi - I hadn't picked up on the fact that a new URLClassloader 
was being created for each forName call. In that case as you say 
everything is working as intended.

But this is a change in behaviour (in terms of memory use) due to the 
PermGen removal. Previously we would use the class_loader to examine the 
dictionary(), but now we create the ClassLoaderData and use that. S I 
have to wonder if there is something we can do to address this?

Thanks,
David
-----


> ||
> 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
>>
>>
>


More information about the hotspot-runtime-dev mailing list