April 2, 2019
share:

Analyze class loader footprint with jcmd

We continue looking at jcmd VM.metaspace and use it - and other commands - to analyze the Metaspace footprint of class loaders.


In our WildFly example of Analyze Metaspace with jcmd, we saw 1041 loaders:

thomas@mainframe:~$ jcmd wildfly VM.metaspace
31997:

Total Usage ( 1041 loaders):

To analyze what they are - with jcmd - we have several choices. I will concentrate on what is new for JDK 11.

jcmd VM.metaspace

Option: “by-spacetype”

First option to be used is by-spacetype. That one groups Metaspace footprint according to different loader types:

$ jcmd wildfly VM.metaspace  by-spacetype
5314:

Usage per space type:

Standard (174 loaders):
  Non-Class: 1177 chunks,     41,28 MB capacity,    36,71 MB ( 89%) used,     4,50 MB ( 11%) free,     1,12 KB ( <1%) waste,    73,56 KB ( <1%) overhead, deallocated: 981 blocks with 540,95 KB
      Class:  736 chunks,      7,27 MB capacity,     5,25 MB ( 72%) used,     1,97 MB ( 27%) free,   192 bytes ( <1%) waste,    46,00 KB ( <1%) overhead, deallocated: 545 blocks with 222,27 KB
       Both: 1913 chunks,     48,54 MB capacity,    41,95 MB ( 86%) used,     6,47 MB ( 13%) free,     1,30 KB ( <1%) waste,   119,56 KB ( <1%) overhead, deallocated: 1526 blocks with 763,22 KB

Boot (1 loader):
  Non-Class:  201 chunks,     16,27 MB capacity,    16,24 MB (>99%) used,    15,01 KB ( <1%) free,   224 bytes ( <1%) waste,    12,56 KB ( <1%) overhead, deallocated: 78 blocks with 31,09 KB
      Class:   48 chunks,      1,73 MB capacity,     1,71 MB (>99%) used,    13,65 KB ( <1%) free,    24 bytes ( <1%) waste,     3,00 KB ( <1%) overhead, deallocated: 44 blocks with 15,23 KB
       Both:  249 chunks,     17,99 MB capacity,    17,95 MB (>99%) used,    28,66 KB ( <1%) free,   248 bytes ( <1%) waste,    15,56 KB ( <1%) overhead, deallocated: 122 blocks with 46,31 KB

Anonymous (869 loaders):
  Non-Class: 1478 chunks,      1,44 MB capacity,  1013,37 KB ( 69%) used,   371,02 KB ( 25%) free,     1,24 KB ( <1%) waste,    92,38 KB (  6%) overhead, deallocated: 445 blocks with 40,47 KB
      Class:  869 chunks,    869,00 KB capacity,   475,30 KB ( 55%) used,   339,39 KB ( 39%) free,     0 bytes (  0%) waste,    54,31 KB (  6%) overhead, deallocated: 0 blocks with 0 bytes
       Both: 2347 chunks,      2,29 MB capacity,     1,45 MB ( 63%) used,   710,41 KB ( 30%) free,     1,24 KB ( <1%) waste,   146,69 KB (  6%) overhead, deallocated: 445 blocks with 40,47 KB

Reflection (6 loaders):
  Non-Class:   12 chunks,     30,00 KB capacity,    19,99 KB ( 67%) used,     9,26 KB ( 31%) free,     0 bytes (  0%) waste,   768 bytes (  2%) overhead, deallocated: 6 blocks with 4,88 KB
      Class:    6 chunks,      6,00 KB capacity,     3,23 KB ( 54%) used,     2,39 KB ( 40%) free,     0 bytes (  0%) waste,   384 bytes (  6%) overhead, deallocated: 0 blocks with 0 bytes
       Both:   18 chunks,     36,00 KB capacity,    23,23 KB ( 65%) used,    11,65 KB ( 32%) free,     0 bytes (  0%) waste,     1,12 KB (  3%) overhead, deallocated: 6 blocks with 4,88 KB


Total Usage ( 1050 loaders):

  Non-Class: 2868 chunks,     59,02 MB capacity,    53,95 MB ( 91%) used,     4,88 MB (  8%) free,     2,58 KB ( <1%) waste,   179,25 KB ( <1%) overhead, deallocated: 1510 blocks with 617,38 KB
      Class: 1659 chunks,      9,85 MB capacity,     7,43 MB ( 75%) used,     2,32 MB ( 24%) free,   216 bytes ( <1%) waste,   103,69 KB (  1%) overhead, deallocated: 589 blocks with 237,49 KB
       Both: 4527 chunks,     68,86 MB capacity,    61,38 MB ( 89%) used,     7,21 MB ( 10%) free,     2,79 KB ( <1%) waste,   282,94 KB ( <1%) overhead, deallocated: 2099 blocks with 854,88 KB

<snip>

Note that the term “loader” in the output is a bit of a misnomer, since what we see here are active ClassLoaderData objects which may include CLDs for anonymous classes.

  • Standard : These are the normal standard class loaders, both the JDK ones (Platform, App) and, in this case, the Wildfly ones.
  • Boot: the JDK bootstrap classloader
  • Anonymous: These are loaders (actually, CLDs) for anonymous classes. As we can see in this example, even though we have almost 900 of them they do not allocate a lot of space, using < 2.29 MB. This picture can be a lot worse in JDK 8, since a lot of work went into bringing memory usage for anonymous classes down.
  • Reflection: These are instances of jdk.internal.reflect.DelegatingClassLoader - glue classes for method invocation via reflection. How many you see depends on how much Reflection you use (obviously) and your Reflection inflaction threshold - see here for details.

Options: “show-loaders” and “show-classes”

We can get more information about which loader/CLD loaded what and why does it use as much space as it does by using VM.metaspace options show-loaders and show-classes.

  • show-loaders shows metaspace usage for each loader/CLD separately.
  • show-classes shows which classes the loader has loaded

Letting this run on our prior WildFly example running on SapMachine 11 yields a lengthy report.

(Full version here).

$ jcmd  wildfly VM.metaspace show-loaders  show-classes
5314:                                                                                                

Usage per loader:

   1: CLD 0x0000000002feada0: <anonymous class>, loaded by "org.jboss.as.server@8.0.0.Final" instance of org.jboss.modules.ModuleClassLoader
      Loaded classes: 
         1: org.jboss.as.server.deployment.ContentRepositoryCleaner$$Lambda$629/0x00000001009cf840
      -total-: 1 class (1 instance class).


  Non-Class:    2 chunks,      2,00 KB capacity,     1,49 KB ( 75%) used,   392 bytes ( 19%) free,     0 bytes (  0%) waste,   128 bytes (  6%) overhead, deallocated: 1 blocks with 64 bytes 
      Class:    1 chunk,       1,00 KB capacity,   592 bytes ( 58%) used,   368 bytes ( 36%) free,     0 bytes (  0%) waste,    64 bytes (  6%) overhead, deallocated: 0 blocks with 0 bytes 
       Both:    3 chunks,      3,00 KB capacity,     2,07 KB ( 69%) used,   760 bytes ( 25%) free,     0 bytes (  0%) waste,   192 bytes (  6%) overhead, deallocated: 1 blocks with 64 bytes 

   2: CLD 0x00000000090aeb50: <anonymous class>, loaded by "org.wildfly.extension.microprofile.metrics-smallrye@16.0.0.Final" instance of org.jboss.modules.ModuleClassLoader
      Loaded classes: 
         1: org.wildfly.extension.microprofile.metrics.MetricCollector$$Lambda$628/0x00000001009c8c40
      -total-: 1 class (1 instance class).

<snip>

  11: CLD 0x0000000008856be0: "org.slf4j.impl@1.0.3.GA" instance of org.jboss.modules.ModuleClassLoader
      Loaded classes: 
         1: org.slf4j.impl.Slf4jLogger
         2: org.slf4j.impl.Slf4jLoggerFactory$1
         3: org.slf4j.impl.Slf4jLoggerFactory
         4: org.slf4j.impl.StaticLoggerBinder
      -total-: 4 classes (4 instance classes).


  Non-Class:    5 chunks,     80,00 KB capacity,    18,71 KB ( 23%) used,    60,96 KB ( 76%) free,    16 bytes ( <1%) waste,   320 bytes ( <1%) overhead, deallocated: 2 blocks with 96 bytes
      Class:    2 chunks,      4,00 KB capacity,     3,45 KB ( 86%) used,   432 bytes ( 11%) free,     0 bytes (  0%) waste,   128 bytes (  3%) overhead, deallocated: 1 blocks with 320 bytes
       Both:    7 chunks,     84,00 KB capacity,    22,16 KB ( 26%) used,    61,38 KB ( 73%) free,    16 bytes ( <1%) waste,   448 bytes ( <1%) overhead, deallocated: 3 blocks with 416 bytes

  12: CLD 0x0000000007ae1400: "org.slf4j@1.7.22.jbossorg-1" instance of org.jboss.modules.ModuleClassLoader
      Loaded classes: 
         1: org.slf4j.helpers.MarkerIgnoringBase
         2: org.slf4j.helpers.NamedLoggerBase
         3: org.slf4j.spi.LocationAwareLogger
         4: org.slf4j.spi.LoggerFactoryBinder
         5: org.slf4j.helpers.Util
         6: org.slf4j.helpers.NOPLoggerFactory
         7: org.slf4j.Logger
         8: org.slf4j.helpers.SubstituteLoggerFactory
         9: org.slf4j.ILoggerFactory
        10: org.slf4j.event.LoggingEvent
        11: org.slf4j.LoggerFactory
      -total-: 11 classes (11 instance classes).

<snip>


  15: CLD 0x000000000692f810: <anonymous class>, loaded by "org.wildfly.extension.undertow@16.0.0.Final" instance of org.jboss.modules.ModuleClassLoader                                                                                                                             
      Loaded classes:
         1: org.wildfly.extension.undertow.HttpInvokerHostService$$Lambda$620/0x0000000100972040
      -total-: 1 class (1 instance class).


  Non-Class:    2 chunks,      2,00 KB capacity,     1,40 KB ( 70%) used,   488 bytes ( 24%) free,     0 bytes (  0%) waste,   128 bytes (  6%) overhead, deallocated: 1 blocks with 40 bytes
      Class:    1 chunk,       1,00 KB capacity,   560 bytes ( 55%) used,   400 bytes ( 39%) free,     0 bytes (  0%) waste,    64 bytes (  6%) overhead, deallocated: 0 blocks with 0 bytes
       Both:    3 chunks,      3,00 KB capacity,     1,95 KB ( 65%) used,   888 bytes ( 29%) free,     0 bytes (  0%) waste,   192 bytes (  6%) overhead, deallocated: 1 blocks with 40 bytes

  16: CLD 0x0000000008f55730: <anonymous class>, loaded by "org.wildfly.extension.undertow@16.0.0.Final" instance of org.jboss.modules.ModuleClassLoader
      Loaded classes:
         1: org.wildfly.extension.undertow.HttpInvokerHostService$$Lambda$619/0x0000000100973440
      -total-: 1 class (1 instance class).


  Non-Class:    2 chunks,      2,00 KB capacity,     1,02 KB ( 51%) used,   880 bytes ( 43%) free,     0 bytes (  0. For example: waste,   128 bytes (  6%) overhead, deallocated: 1 blocks with 64 bytes
      Class:    1 chunk,       1,00 KB capacity,   584 bytes ( 57%) used,   376 bytes ( 37%) free,     0 bytes (  0. For example: waste,    64 bytes (  6%) overhead, deallocated: 0 blocks with 0 bytes
       Both:    3 chunks,      3,00 KB capacity,     1,59 KB ( 53%) used,     1,23 KB ( 41%) free,     0 bytes (  0. For example: waste,   192 bytes (  6%) overhead, deallocated: 1 blocks with 64 bytes

  17: CLD 0x000000000885aa20: <anonymous class>, loaded by "org.wildfly.extension.undertow@16.0.0.Final" instance of org.jboss.modules.ModuleClassLoader
      Loaded classes:
         1: org.wildfly.extension.undertow.HttpInvokerHostService$$Lambda$618/0x0000000100973040
      -total-: 1 class (1 instance class).

This shows us, per loader, which classes have been loaded and how much Metaspace we use for this.

The printout is pretty straightforward and easy to understand: We see the CLD address, the class loader name and its class:

CLD 0x0000000008856be0: "org.slf4j.impl@1.0.3.GA" instance of org.jboss.modules.ModuleClassLoader

For CLDs belonging to anonymous classes, we see no name (since it has none) but we see which loader hosts this CLD, and the name of the anonymous class, which is helpful in understanding its source:

  17: CLD 0x000000000885aa20: <anonymous class>, loaded by "org.wildfly.extension.undertow@16.0.0.Final" instance of org.jboss.modules.ModuleClassLoader
      Loaded classes:
         1: org.wildfly.extension.undertow.HttpInvokerHostService$$Lambda$618/0x0000000100973040

in this case the CLD is for an anoymous class generated for one of the Lambda expressions in java/org/wildfly/extension/undertow/HttpInvokerHostService.java.

VM.classloaders

Another new diagnostic command we (SAP) added to JDK 11 was VM.classloaders.

thomas@mainframe:~$ jcmd wildfly help VM.classloaders
17680:
VM.classloaders
Prints classloader hierarchy.

Impact: Medium: Depends on number of class loaders and classes loaded.

Permission: java.lang.management.ManagementPermission(monitor)

Syntax : VM.classloaders [options]

Options: (options must be specified using the <key> or <key>=<value> syntax)
        show-classes : [optional] Print loaded classes. (BOOLEAN, false)
        verbose : [optional] Print detailed information. (BOOLEAN, false)
        fold :  Show loaders of the same name and class as one. (BOOLEAN, true)

In its most basic form, it prints the loader tree:

$ /shared/projects/openjdk/jdks/sapmachine11/bin/jcmd wildfly  VM.classloaders
17680:
+-- <bootstrap>
      |     
      +-- "platform", jdk.internal.loader.ClassLoaders$PlatformClassLoader
            |     
            +-- "app", jdk.internal.loader.ClassLoaders$AppClassLoader
                  |     
                  +-- "org.apache.xerces@2.12.0.SP02", org.jboss.modules.ModuleClassLoader
                  |           
                  +-- "org.apache.xalan", org.jboss.modules.ModuleClassLoader
                  |           
                  +-- "org.codehaus.woodstox@5.0.3", org.jboss.modules.ModuleClassLoader
                  |           
                  +-- "org.jboss.as.standalone", org.jboss.modules.ModuleClassLoader
                  |           
                  +-- "org.jboss.vfs@3.2.14.Final", org.jboss.modules.ModuleClassLoader
                  |           
                  +-- "org.jboss.logmanager@2.1.7.Final", org.jboss.modules.ModuleClassLoader
                  |           
                  +-- "org.jboss.stdio@1.0.2.GA", org.jboss.modules.ModuleClassLoader
                  |           
                  +-- "org.jboss.as.version@8.0.0.Final", org.jboss.modules.ModuleClassLoader
                  |           
                  +-- "org.wildfly.client.config@1.0.1.Final", org.jboss.modules.ModuleClassLoader
....

Used with show-classes and verbose, it prints all loaded classes - including anonymous classes, as well as the addresses of the associated ClassLoaderData objects:

17680:                                                                                               <skip>
                  +-- "org.jboss.staxmapper@1.3.0.Final", org.jboss.modules.ModuleClassLoader
                  |
                  |                  Loader Oop: 0x00000000e048e9d8
                  |                 Loader Data: 0x0000000002dad8d0
                  |                Loader Klass: 0x0000000100090040
                  |
                  |                     Classes: org.jboss.staxmapper.XMLElementWriter
                  |                              org.jboss.staxmapper.XMLElementReader
                  |                              org.jboss.staxmapper.XMLMapper$Factory
                  |                              org.jboss.staxmapper.XMLMapper
                  |                              org.jboss.staxmapper.XMLMapperImpl
                  |                              org.jboss.staxmapper.XMLExtendedStreamReader
                  |                              org.jboss.staxmapper.XMLExtendedStreamWriter
                  |                              org.jboss.staxmapper.XMLExtendedStreamReaderImpl
                  |                              org.jboss.staxmapper.FixedXMLStreamReader
                  |                              org.jboss.staxmapper.XMLExtendedStreamReaderImpl$Context
                  |                              org.jboss.staxmapper.Spliterator
                  |                              (11 classes)
                  |
                  |           Anonymous Classes: org.jboss.staxmapper.XMLMapperImpl$$Lambda$148/0x000000010034f440  (Loader Data: 0x0000000003817240)
                  |                              org.jboss.staxmapper.XMLMapperImpl$$Lambda$147/0x000000010034f040  (Loader Data: 0x00000000038183e0)
                  |                              org.jboss.staxmapper.XMLMapperImpl$$Lambda$146/0x0000000100349c40  (Loader Data: 0x00000000037bb3e0)
                  |                              (3 anonymous classes)
<skip>