geode-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Kirk Lund (Jira)" <j...@apache.org>
Subject [jira] [Updated] (GEODE-7370) ClassGraph library causes large memory leak in Geode after adding geode-log4j
Date Mon, 28 Oct 2019 19:52:00 GMT

     [ https://issues.apache.org/jira/browse/GEODE-7370?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]

Kirk Lund updated GEODE-7370:
-----------------------------
    Description: 
According to the source code and documentation, io.github.classgraph.ScanResult must be closed
to avoid memory and file leaks.

I identified a large memory leak that apparently after adding geode-log4j. Surprisingly the
cause ended up being an instance of ScanResult which is used by the management code to search
the classpath for user classes that implement geode functions or gfsh commands.

Geode currently depends on ClassGraph version 4.0.6, but the library is up to version 4.8.52
(averaging around a dozen releases per month).

JVM bytes in use by io.github.classgraph after closing all ScanResult instances:
* Before geode-log4j with ClassGraph 4.0.6: 20,488 bytes
* Before geode-log4j with ClassGraph 4.8.52: 1,056 bytes
* After geode-log4j with ClassGraph 4.0.6: 56,753,008 bytes
* After geode-log4j with ClassGraph 4.8.52: 1,056 bytes

Given the above results of my testing, I believe we need to keep this dependency up-to-date
and upgrade to 4.8.52.

More detailed analysis below:

Before: 802687154131af16d350bf39d152feb4685ba7e6 (sha before geode-log4j)
Before-w/upgrade: Before w/ ClassGraph upgraded from 4.0.6 to 4.8.52
<< Geode-log4j: efc2362d2bae0877a427ce2c29beae94118d6567 (geode-log4j) >>
After: dffcb9446aef09c7bf6e626121f4d2ec5c74586f (async alerts)
After-w/upgrade: After w/ ClassGraph upgraded from 4.0.6 to 4.8.52

Java process memory sizes:

  Before:
    ChildVMs
    22297  java         0.0    00:07.51 32     1    104   252M   0B     0B     22220 22286
sleeping *0[1]            0.00000 0.00000    501
    22295  java         0.0    00:07.72 32     1    104   259M   0B     0B     22220 22286
sleeping *0[1]            0.00000 0.00000    501
    22291  java         0.1    00:11.66 32     1    104   291M   0B     0B     22220 22286
sleeping *0[1]            0.00000 0.00000    501
    22289  java         0.1    00:11.68 32     1    104   300M   0B     0B     22220 22286
sleeping *0[1]            0.00000 0.00000    501
    22287  java         0.5    00:07.67 64     1    168   276M+  0B     0B     22220 22286
sleeping *0[1]            0.00000 0.00000    501

    GradleWorkerMain
    22286  java         0.4    00:03.55 67     1    174   184M+  0B     0B     22220 22220
sleeping *0[1]            0.00000 0.00000    501
    GradleWrapperMain
    22173  java         0.1    00:01.63 28     1    96    88M+   0B     0B     22173 86991
sleeping *0[1]            0.00000 0.00000    501
    GradleDaemon
    22220  java         0.6    00:52.27 81     1    201   814M   0B     0B     22220 22173
sleeping *0[1]            0.00000 0.00000    501

  Before-w/upgrade:

    ChildVMs
    25789  java         0.0  00:06.93 31     1    101   257M   0B     0B     25714 25779 sleeping
*0[1]           0.00000 0.00000    501
    25788  java         0.1  00:06.93 31     1    101   259M+  0B     0B     25714 25779 sleeping
*0[1]           0.00000 0.00000    501
    25784  java         0.0  00:10.37 31     1    101   286M   0B     0B     25714 25779 sleeping
*0[1]           0.00000 0.00000    501
    25782  java         0.1  00:11.68 31     1    101   278M   0B     0B     25714 25779 sleeping
*0[1]           0.00000 0.00000    501
    25780  java         0.3  00:07.84 63/1   1    165   308M+  0B     0B     25714 25779 running
 *0[1]           0.00000 0.00000    501

    GradleWorkerMain
    25779  java         0.1  00:03.39 60     1    160   183M   0B     0B     25714 25714 sleeping
*0[1]           0.00000 0.00000    501
    GradleDaemon
    25714  java         0.8  00:48.79 79     1    197   793M   0B     0B     25714 25667 sleeping
*0[1]           0.00000 0.00000    501
    GradleWrapperMain
    25667  java         0.2  00:02.16 28     1    96    101M+  0B     0B     25667 86991 sleeping
*0[1]           0.00000 0.00000    501

  After:
    ChildVMs
    21056  java         0.1  00:06.67 31     1    101   256M   0B     0B     20988 21049 sleeping
*0[1]            0.00000 0.00000    501
    21055  java         0.1  00:06.82 31     1    101   264M+  0B     0B     20988 21049 sleeping
*0[1]            0.00000 0.00000    501
    21053  java         0.1  00:15.95 31     1    101   373M   0B     0B     20988 21049 sleeping
*0[1]            0.00000 0.00000    501
    21051  java         0.3  00:14.96 31     1    101   363M+  0B     0B     20988 21049 sleeping
*0[1]            0.00000 0.00000    501
    21050  java         0.5  00:12.07 63     1    165   343M+  0B     0B     20988 21049 sleeping
*0[1]            0.00000 0.00000    501

    GradleWorkerMain
    21049  java         0.2  00:06.99 60     1    160   321M+  0B     0B     20988 20988 sleeping
*0[1]            0.00000 0.00000    501
    GradleWrapperMain
    20941  java         0.2  00:02.14 28     1    96    101M+  0B     0B     20941 86991 sleeping
*0[1]            0.00000 0.00000    501
    GradleDaemon
    20988  java         0.8  00:53.39 81     1    202   963M   0B     0B     20988 20941 sleeping
*0[1]            0.00000 0.00000    501

  After-w/upgrade:
    ChildVMs
    24298  java         0.1  00:06.29 32     1    104   250M   0B     0B     24231 24291 sleeping
*0[1]            0.00000 0.00000    501
    24297  java         0.1  00:06.59 32     1    104   262M   0B     0B     24231 24291 sleeping
*0[1]            0.00000 0.00000    501
    24295  java         0.1  00:14.97 32     1    104   362M   0B     0B     24231 24291 sleeping
*0[1]            0.00000 0.00000    501
    24293  java         0.2  00:15.44 32     1    104   376M+  0B     0B     24231 24291 sleeping
*0[1]            0.00000 0.00000    501
    24292  java         0.7  00:10.36 64     1    168   327M   0B     0B     24231 24291 sleeping
*0[1]            0.00000 0.00000    501

    GraldeWorkerMain
    24291  java         0.7  00:06.07 67     1    174   320M+  0B     0B     24231 24231 sleeping
*0[1]            0.00000 0.00000    501
    GradleWrapperMain
    24184  java         0.3  00:01.39 28     1    96    89M+   0B     0B     24184 86991 sleeping
*0[1]            0.00000 0.00000    501
    GradleDaemon
    24231  java         1.0  00:46.21 81     1    201   805M   0B     0B     24231 24184 sleeping
*0[1]            0.00000 0.00000    501

Bytes in use - biggest objects:

  Before:
    sun.misc.Launcher$AppClassLoader - 883,984
  Before-w/upgrade:
    sun.misc.Launcher$AppClassLoader - 915,384
  After:
    io.github.classgraph.ScanResult - 11,373,088
  After-w/upgrade:
    sun.misc.Launcher$AppClassLoader - 1,256,904

Bytes in use - per package:

org.apache.geode.internal.logging -
  Before: 253,520
  Before-w/upgrade: 253,520
  After: 33,576
  After-w/upgrade: 21,152
org.apache.geode.logging -
  Before: 0
  Before-w/upgrade: 0
  After: 233,104
  After-w/upgrade: 231,968
org.apache.logging.log4j -
  Before: 581,184
  Before-w/upgrade:  581,184
  After: 605,904
  After-w/upgrade: 584,576
java.util.logging -
  Before: 45,632
  Before-w/upgrade: 45,632
  After: 45,632
  After-w/upgrade: 45,632

io.micrometer -
  Before: 249,408
  Before-w/upgrade: 249,408
  After: 258,608
  After-w/upgrade: 249,408
org.apache.geode.internal.statistics -
  Before: 109,608
  Before-w/upgrade: 109,024
  After: 123,832
  After-w/upgrade: 109,024
org.apache.geode.internal.metrics -
  Before: 32,368
  Before-w/upgrade:
  After: 32,488
  After-w/upgrade: 32,368

org.apache.geode.internal.cache -
  Before: 1,034,624
  Before-w/upgrade: 1,034,560
  After: 1,065,312
  After-w/upgrade: 1,034,224
org.apache.geode.internal.util.concurrent -
  Before: 129,328
  Before-w/upgrade: 129,328
  After: 136,048
  After-w/upgrade: 129,264
org.apache.geode.management -
  Before: 9,592
  Before-w/upgrade: 9,592
  After: 28,408
  After-w/upgrade: 9,592
org.apache.geode.distributed -
  Before: 224,960
  Before-w/upgrade: 224,408
  After: 256,272
  After-w/upgrade: 223,720

io.github.classgraph -
  Before: 20,488
  Before-w/upgrade: 1,056
  After: 56,753,008
  After-w/upgrade: 1,056

java -
  Before: 38,697,928
  Before-w/upgrade: 59,048,552
  After: 143,295,448
  After-w/upgrade: 52,397,344
sun -
  Before: 2,464,792
  Before-w/upgrade: 2,593,712
  After: 3,359,248
  After-w/upgrade: 3,126,280

System class loader -
  Before: 356,651 objects, 38,697,928 bytes, 4,295 classes, 3,028 classes w/o instances
  Before-w/upgrade: 883,377 objects, 59,048,552 bytes, 4,344 classes, 3,077 classes w/o instances
  After: 1,802,231 objects, 143,295,448 bytes, 8,715 classes, 7,191 classes w/o instances
  After-w/upgrade: 712,102 objects, 52,397,344 bytes, 8,765 classes, 7,461 classes w/o instances
AppClassLoader -
  Before: 11,275 objects, 7,020,720 bytes, 2,885 classes, 1,896 classes w/o instances
  Before-w/upgrade: 10,467 objects, 7,068,488 bytes, 2,921 classes, 1,943 classes w/o instances
  After: 20,336 objects, 64,013,592 bytes, 2,929 classes, 1,451 classes w/o instances
  After-w/upgrade: 10,988 objects, 7,273,232 bytes, 2,980 classes, 1,980 classes w/o instances
Geode ClassPathLoader$1 -
  Before: 2 objects, 130,480 bytes, 1 classes, 0 classes w/o instances
  Before-w/upgrade: 2 objects, 130,480 bytes, 1 classes, 0 classes w/o instances
  After: 2 Objects, 130,680 bytes, 1 classes, 0 classes w/o instances
  After-w/upgrade: 2 objects, 130,680 bytes, 1 classes, 0 classes w/o instances

Objects unreachable from GC roots, but not yet collected -
  Before: 26,669,744
  Before-w/upgrade: 46,758,496
  After: 112,345,880
  After-w/upgrade: 35,093,072
Objects reachable from GC roots via strong references -
  Before: 12,028,184
  Before-w/upgrade: 12,290,056
  After: 30,949,568
  After-w/upgrade: 17,304,272
Objects pending finalization (finalizer queue objects unreachable via strong references) -
  Before: 241,776
  Before-w/upgrade: 252,192
  After: 13,564,760
  After-w/upgrade: 295,160
Objects reachable from GC roots via weak and/or soft references only -
  Before: 91,048
  Before-w/upgrade: 106,488
  After: 586,616
  After-w/upgrade: 51,616

  was:
According to the source code and documentation, io.github.classgraph.ScanResult must be closed
to avoid memory and file leaks.

I identified a large memory leak that apparently after adding geode-log4j. Surprisingly the
cause ended up being an instance of ScanResult which is used by the management code to search
the classpath for user classes that implement geode functions or gfsh commands.

Geode currently depends on ClassGraph version 4.0.6, but the library is up to version 4.8.52
(averaging around a dozen releases per month).

JVM bytes in use by io.github.classgraph after closing all ScanResult instances:
* Before geode-log4j with ClassGraph 4.0.6: 20,488 bytes
* Before geode-log4j with ClassGraph 4.8.52: 1,056 bytes
* After geode-log4j with ClassGraph 4.0.6: 56,753,008 bytes
* After geode-log4j with ClassGraph 4.8.52: 1,056 bytes

Given the above results of my testing, I believe we need to keep this dependency up-to-date
and upgrade to 4.8.52.


> ClassGraph library causes large memory leak in Geode after adding geode-log4j
> -----------------------------------------------------------------------------
>
>                 Key: GEODE-7370
>                 URL: https://issues.apache.org/jira/browse/GEODE-7370
>             Project: Geode
>          Issue Type: Bug
>          Components: management
>            Reporter: Kirk Lund
>            Assignee: Kirk Lund
>            Priority: Major
>          Time Spent: 10m
>  Remaining Estimate: 0h
>
> According to the source code and documentation, io.github.classgraph.ScanResult must
be closed to avoid memory and file leaks.
> I identified a large memory leak that apparently after adding geode-log4j. Surprisingly
the cause ended up being an instance of ScanResult which is used by the management code to
search the classpath for user classes that implement geode functions or gfsh commands.
> Geode currently depends on ClassGraph version 4.0.6, but the library is up to version
4.8.52 (averaging around a dozen releases per month).
> JVM bytes in use by io.github.classgraph after closing all ScanResult instances:
> * Before geode-log4j with ClassGraph 4.0.6: 20,488 bytes
> * Before geode-log4j with ClassGraph 4.8.52: 1,056 bytes
> * After geode-log4j with ClassGraph 4.0.6: 56,753,008 bytes
> * After geode-log4j with ClassGraph 4.8.52: 1,056 bytes
> Given the above results of my testing, I believe we need to keep this dependency up-to-date
and upgrade to 4.8.52.
> More detailed analysis below:
> Before: 802687154131af16d350bf39d152feb4685ba7e6 (sha before geode-log4j)
> Before-w/upgrade: Before w/ ClassGraph upgraded from 4.0.6 to 4.8.52
> << Geode-log4j: efc2362d2bae0877a427ce2c29beae94118d6567 (geode-log4j) >>
> After: dffcb9446aef09c7bf6e626121f4d2ec5c74586f (async alerts)
> After-w/upgrade: After w/ ClassGraph upgraded from 4.0.6 to 4.8.52
> Java process memory sizes:
>   Before:
>     ChildVMs
>     22297  java         0.0    00:07.51 32     1    104   252M   0B     0B     22220
22286 sleeping *0[1]            0.00000 0.00000    501
>     22295  java         0.0    00:07.72 32     1    104   259M   0B     0B     22220
22286 sleeping *0[1]            0.00000 0.00000    501
>     22291  java         0.1    00:11.66 32     1    104   291M   0B     0B     22220
22286 sleeping *0[1]            0.00000 0.00000    501
>     22289  java         0.1    00:11.68 32     1    104   300M   0B     0B     22220
22286 sleeping *0[1]            0.00000 0.00000    501
>     22287  java         0.5    00:07.67 64     1    168   276M+  0B     0B     22220
22286 sleeping *0[1]            0.00000 0.00000    501
>     GradleWorkerMain
>     22286  java         0.4    00:03.55 67     1    174   184M+  0B     0B     22220
22220 sleeping *0[1]            0.00000 0.00000    501
>     GradleWrapperMain
>     22173  java         0.1    00:01.63 28     1    96    88M+   0B     0B     22173
86991 sleeping *0[1]            0.00000 0.00000    501
>     GradleDaemon
>     22220  java         0.6    00:52.27 81     1    201   814M   0B     0B     22220
22173 sleeping *0[1]            0.00000 0.00000    501
>   Before-w/upgrade:
>     ChildVMs
>     25789  java         0.0  00:06.93 31     1    101   257M   0B     0B     25714 25779
sleeping *0[1]           0.00000 0.00000    501
>     25788  java         0.1  00:06.93 31     1    101   259M+  0B     0B     25714 25779
sleeping *0[1]           0.00000 0.00000    501
>     25784  java         0.0  00:10.37 31     1    101   286M   0B     0B     25714 25779
sleeping *0[1]           0.00000 0.00000    501
>     25782  java         0.1  00:11.68 31     1    101   278M   0B     0B     25714 25779
sleeping *0[1]           0.00000 0.00000    501
>     25780  java         0.3  00:07.84 63/1   1    165   308M+  0B     0B     25714 25779
running  *0[1]           0.00000 0.00000    501
>     GradleWorkerMain
>     25779  java         0.1  00:03.39 60     1    160   183M   0B     0B     25714 25714
sleeping *0[1]           0.00000 0.00000    501
>     GradleDaemon
>     25714  java         0.8  00:48.79 79     1    197   793M   0B     0B     25714 25667
sleeping *0[1]           0.00000 0.00000    501
>     GradleWrapperMain
>     25667  java         0.2  00:02.16 28     1    96    101M+  0B     0B     25667 86991
sleeping *0[1]           0.00000 0.00000    501
>   After:
>     ChildVMs
>     21056  java         0.1  00:06.67 31     1    101   256M   0B     0B     20988 21049
sleeping *0[1]            0.00000 0.00000    501
>     21055  java         0.1  00:06.82 31     1    101   264M+  0B     0B     20988 21049
sleeping *0[1]            0.00000 0.00000    501
>     21053  java         0.1  00:15.95 31     1    101   373M   0B     0B     20988 21049
sleeping *0[1]            0.00000 0.00000    501
>     21051  java         0.3  00:14.96 31     1    101   363M+  0B     0B     20988 21049
sleeping *0[1]            0.00000 0.00000    501
>     21050  java         0.5  00:12.07 63     1    165   343M+  0B     0B     20988 21049
sleeping *0[1]            0.00000 0.00000    501
>     GradleWorkerMain
>     21049  java         0.2  00:06.99 60     1    160   321M+  0B     0B     20988 20988
sleeping *0[1]            0.00000 0.00000    501
>     GradleWrapperMain
>     20941  java         0.2  00:02.14 28     1    96    101M+  0B     0B     20941 86991
sleeping *0[1]            0.00000 0.00000    501
>     GradleDaemon
>     20988  java         0.8  00:53.39 81     1    202   963M   0B     0B     20988 20941
sleeping *0[1]            0.00000 0.00000    501
>   After-w/upgrade:
>     ChildVMs
>     24298  java         0.1  00:06.29 32     1    104   250M   0B     0B     24231 24291
sleeping *0[1]            0.00000 0.00000    501
>     24297  java         0.1  00:06.59 32     1    104   262M   0B     0B     24231 24291
sleeping *0[1]            0.00000 0.00000    501
>     24295  java         0.1  00:14.97 32     1    104   362M   0B     0B     24231 24291
sleeping *0[1]            0.00000 0.00000    501
>     24293  java         0.2  00:15.44 32     1    104   376M+  0B     0B     24231 24291
sleeping *0[1]            0.00000 0.00000    501
>     24292  java         0.7  00:10.36 64     1    168   327M   0B     0B     24231 24291
sleeping *0[1]            0.00000 0.00000    501
>     GraldeWorkerMain
>     24291  java         0.7  00:06.07 67     1    174   320M+  0B     0B     24231 24231
sleeping *0[1]            0.00000 0.00000    501
>     GradleWrapperMain
>     24184  java         0.3  00:01.39 28     1    96    89M+   0B     0B     24184 86991
sleeping *0[1]            0.00000 0.00000    501
>     GradleDaemon
>     24231  java         1.0  00:46.21 81     1    201   805M   0B     0B     24231 24184
sleeping *0[1]            0.00000 0.00000    501
> Bytes in use - biggest objects:
>   Before:
>     sun.misc.Launcher$AppClassLoader - 883,984
>   Before-w/upgrade:
>     sun.misc.Launcher$AppClassLoader - 915,384
>   After:
>     io.github.classgraph.ScanResult - 11,373,088
>   After-w/upgrade:
>     sun.misc.Launcher$AppClassLoader - 1,256,904
> Bytes in use - per package:
> org.apache.geode.internal.logging -
>   Before: 253,520
>   Before-w/upgrade: 253,520
>   After: 33,576
>   After-w/upgrade: 21,152
> org.apache.geode.logging -
>   Before: 0
>   Before-w/upgrade: 0
>   After: 233,104
>   After-w/upgrade: 231,968
> org.apache.logging.log4j -
>   Before: 581,184
>   Before-w/upgrade:  581,184
>   After: 605,904
>   After-w/upgrade: 584,576
> java.util.logging -
>   Before: 45,632
>   Before-w/upgrade: 45,632
>   After: 45,632
>   After-w/upgrade: 45,632
> io.micrometer -
>   Before: 249,408
>   Before-w/upgrade: 249,408
>   After: 258,608
>   After-w/upgrade: 249,408
> org.apache.geode.internal.statistics -
>   Before: 109,608
>   Before-w/upgrade: 109,024
>   After: 123,832
>   After-w/upgrade: 109,024
> org.apache.geode.internal.metrics -
>   Before: 32,368
>   Before-w/upgrade:
>   After: 32,488
>   After-w/upgrade: 32,368
> org.apache.geode.internal.cache -
>   Before: 1,034,624
>   Before-w/upgrade: 1,034,560
>   After: 1,065,312
>   After-w/upgrade: 1,034,224
> org.apache.geode.internal.util.concurrent -
>   Before: 129,328
>   Before-w/upgrade: 129,328
>   After: 136,048
>   After-w/upgrade: 129,264
> org.apache.geode.management -
>   Before: 9,592
>   Before-w/upgrade: 9,592
>   After: 28,408
>   After-w/upgrade: 9,592
> org.apache.geode.distributed -
>   Before: 224,960
>   Before-w/upgrade: 224,408
>   After: 256,272
>   After-w/upgrade: 223,720
> io.github.classgraph -
>   Before: 20,488
>   Before-w/upgrade: 1,056
>   After: 56,753,008
>   After-w/upgrade: 1,056
> java -
>   Before: 38,697,928
>   Before-w/upgrade: 59,048,552
>   After: 143,295,448
>   After-w/upgrade: 52,397,344
> sun -
>   Before: 2,464,792
>   Before-w/upgrade: 2,593,712
>   After: 3,359,248
>   After-w/upgrade: 3,126,280
> System class loader -
>   Before: 356,651 objects, 38,697,928 bytes, 4,295 classes, 3,028 classes w/o instances
>   Before-w/upgrade: 883,377 objects, 59,048,552 bytes, 4,344 classes, 3,077 classes w/o
instances
>   After: 1,802,231 objects, 143,295,448 bytes, 8,715 classes, 7,191 classes w/o instances
>   After-w/upgrade: 712,102 objects, 52,397,344 bytes, 8,765 classes, 7,461 classes w/o
instances
> AppClassLoader -
>   Before: 11,275 objects, 7,020,720 bytes, 2,885 classes, 1,896 classes w/o instances
>   Before-w/upgrade: 10,467 objects, 7,068,488 bytes, 2,921 classes, 1,943 classes w/o
instances
>   After: 20,336 objects, 64,013,592 bytes, 2,929 classes, 1,451 classes w/o instances
>   After-w/upgrade: 10,988 objects, 7,273,232 bytes, 2,980 classes, 1,980 classes w/o
instances
> Geode ClassPathLoader$1 -
>   Before: 2 objects, 130,480 bytes, 1 classes, 0 classes w/o instances
>   Before-w/upgrade: 2 objects, 130,480 bytes, 1 classes, 0 classes w/o instances
>   After: 2 Objects, 130,680 bytes, 1 classes, 0 classes w/o instances
>   After-w/upgrade: 2 objects, 130,680 bytes, 1 classes, 0 classes w/o instances
> Objects unreachable from GC roots, but not yet collected -
>   Before: 26,669,744
>   Before-w/upgrade: 46,758,496
>   After: 112,345,880
>   After-w/upgrade: 35,093,072
> Objects reachable from GC roots via strong references -
>   Before: 12,028,184
>   Before-w/upgrade: 12,290,056
>   After: 30,949,568
>   After-w/upgrade: 17,304,272
> Objects pending finalization (finalizer queue objects unreachable via strong references)
-
>   Before: 241,776
>   Before-w/upgrade: 252,192
>   After: 13,564,760
>   After-w/upgrade: 295,160
> Objects reachable from GC roots via weak and/or soft references only -
>   Before: 91,048
>   Before-w/upgrade: 106,488
>   After: 586,616
>   After-w/upgrade: 51,616



--
This message was sent by Atlassian Jira
(v8.3.4#803005)

Mime
View raw message