JRuby

Memory Leak

Details

  • Type: Bug Bug
  • Status: Closed Closed
  • Priority: Major Major
  • Resolution: Fixed
  • Affects Version/s: JRuby 1.1.5
  • Fix Version/s: None
  • Component/s: Java Integration, JRuby-extras
  • Labels:
    None
  • Environment:
    Submitted project is an eclipse project. Needs jruby 1.1.5, jrubyengine 1.1.6
  • Testcase included:
    yes
  • Number of attachments :
    3

Description

Repeated calls to scriptEngine.invokeMethod() result in a memory growth. Attached is a sample to reproduce the problem. Investigation in the context of my project seemed to suggest some buildup happening in VariableCachingCallSite.

Attachments

  1. Java Source File
    MemoryLeak.java
    24/Feb/10 2:55 PM
    2 kB
    Yoko Harada
  1. heapusage.png
    99 kB
    24/Feb/10 2:55 PM

Activity

Ascending order - Click to sort in descending order
Hide
Permalink
Thomas E Enebo added a comment -

Can you retry this with trunk build of JRuby? By default JIT is enabled, which means that we will compile Ruby methods over time. This will grow memory usage over time up to a point where it stops. We have a max size for number of compiled methods (see jruby --properties). You can either try and tweak values to take this out of the equation or just let your app run for a long time.

If you still see this, then we can see if it has something to do with how jrubyengine interfaces with JRuby internals perhaps?

Show
Thomas E Enebo added a comment - Can you retry this with trunk build of JRuby? By default JIT is enabled, which means that we will compile Ruby methods over time. This will grow memory usage over time up to a point where it stops. We have a max size for number of compiled methods (see jruby --properties). You can either try and tweak values to take this out of the equation or just let your app run for a long time. If you still see this, then we can see if it has something to do with how jrubyengine interfaces with JRuby internals perhaps?
Hide
Permalink
Charles Oliver Nutter added a comment -

No followup and the code provided can't easily be built into a reproducible example.

Show
Charles Oliver Nutter added a comment - No followup and the code provided can't easily be built into a reproducible example.
Hide
Permalink
Pankaj M. Tolani added a comment -

attached snippet is standalone java eclipse project. same code can be run from any ide or just java cmd line. so why is it difficult to reproduce this? please let me know if you need any inputs!

Show
Pankaj M. Tolani added a comment - attached snippet is standalone java eclipse project. same code can be run from any ide or just java cmd line. so why is it difficult to reproduce this? please let me know if you need any inputs!
Hide
Permalink
Charles Oliver Nutter added a comment -

Ok, just give me a command line I can run to see the leaking in action. I did not expect you to still be out there

Also, if you could try on a more recent JRuby, it may have been fixed; JRuby 1.1.5 is almost a year old now.

Show
Charles Oliver Nutter added a comment - Ok, just give me a command line I can run to see the leaking in action. I did not expect you to still be out there Also, if you could try on a more recent JRuby, it may have been fixed; JRuby 1.1.5 is almost a year old now.
Hide
Permalink
Lars J. Nilsson added a comment - - edited

We just ran into a memory leak as well in a real world case.

We tested it on JRuby 1.4.0, and it's really quite simple to reproduce:

try {
    ScriptEngineManager man = new ScriptEngineManager();
    long end = System.currentTimeMillis() + (5 * 60000);
    System.out.println("Generating garbage for 5 mins...");
    while(end > System.currentTimeMillis()) {
        /*
         * creating the engine here corresponds to our real-world
         * case, but you can move the two wollowing lines outside the
         * loop with the same result
         */
        ScriptEngine engine = man.getEngineByExtension("rb");
        engine.eval(new StringReader("def methodA() y = 10 end"));
        ((Invocable)engine).invokeFunction("methodA");
        /*
         * We'll do a small wait here to let the VM breathe...
         */
        Thread.sleep(5);
    }
    /*
     * And here we'll simply hang the system so that 
     * a memory dump can be created etc...
     */
    System.out.println("Garbage generated, hanging...");
    synchronized(this) {
        this.wait();
    }
} catch(Exception e) {
    e.printStackTrace();
}

Running this with monitoring tools such as JConsole will shows that the old generation heap is growing without stop... It's not conclusive, but you should be able to run a heap analysis on this and figure it out.

Cheers
/Lars J. Nilsson
www.cubeia.com

Show
Lars J. Nilsson added a comment - - edited We just ran into a memory leak as well in a real world case. We tested it on JRuby 1.4.0, and it's really quite simple to reproduce: 
try {
    ScriptEngineManager man = new ScriptEngineManager();
    long end = System.currentTimeMillis() + (5 * 60000);
    System.out.println("Generating garbage for 5 mins...");
    while(end > System.currentTimeMillis()) {
        /*
         * creating the engine here corresponds to our real-world
         * case, but you can move the two wollowing lines outside the
         * loop with the same result
         */
        ScriptEngine engine = man.getEngineByExtension("rb");
        engine.eval(new StringReader("def methodA() y = 10 end"));
        ((Invocable)engine).invokeFunction("methodA");
        /*
         * We'll do a small wait here to let the VM breathe...
         */
        Thread.sleep(5);
    }
    /*
     * And here we'll simply hang the system so that 
     * a memory dump can be created etc...
     */
    System.out.println("Garbage generated, hanging...");
    synchronized(this) {
        this.wait();
    }
} catch(Exception e) {
    e.printStackTrace();
}
Running this with monitoring tools such as JConsole will shows that the old generation heap is growing without stop... It's not conclusive, but you should be able to run a heap analysis on this and figure it out. Cheers /Lars J. Nilsson www.cubeia.com
Hide
Permalink
Yoko Harada added a comment -

I think the memory leak discussed here doesn't happen on the latest JRuby version. I watched heap usage while running attached file, MemoryLeak.java, which is the same code displayed here. I also attached the heap usage graph generated by JConsole. The output from jstat was:

S0 S1 E O P YGC YGCT FGC FGCT GCT
0.00 0.00 30.60 65.93 93.41 348 0.254 1 0.044 0.298
0.00 29.38 0.00 65.93 93.42 501 0.362 1 0.044 0.406
30.48 0.00 72.04 65.93 93.42 654 0.469 1 0.044 0.513
0.00 29.38 0.00 65.93 93.42 809 0.566 1 0.044 0.610
0.00 29.38 0.00 65.93 93.42 963 0.672 1 0.044 0.717
34.58 0.00 0.00 65.93 93.42 1118 0.772 1 0.044 0.817
0.00 29.38 29.95 65.93 93.42 1271 0.875 1 0.044 0.919
34.58 0.00 0.00 65.93 93.42 1426 0.979 1 0.044 1.023
34.58 0.00 59.36 65.93 93.42 1580 1.084 1 0.044 1.128
34.58 0.00 88.28 65.93 93.42 1735 1.183 1 0.044 1.228

My environment is:
electra:Birch yoko$ java -version
java version "1.5.0_22"
Java(TM) 2 Runtime Environment, Standard Edition (build 1.5.0_22-b03-333-9M3125)
Java HotSpot(TM) Client VM (build 1.5.0_22-147, mixed mode, sharing)

electra:jruby~main yoko$ jruby -v
jruby 1.5.0.dev (ruby 1.8.7 patchlevel 174) (2010-02-24 944db04) (Java HotSpot(TM) Client VM 1.5.0_22) [i386-java]

I ran the attached program as in below:

java -cp /Users/yoko/DevSpace/jruby~main/lib/jruby.jar:/Users/yoko/DevSpace/jruby~main/build_lib/livetribe-jsr223-2.0.6.jar:build redbridge.MemoryLeak
Generating garbage for 5 mins...
Garbage generated, hanging...

I also ran the program in scripting-ruby.zip. It went "Creating job number 99999" and said "done." The heap usage curve was quite similar to the one I attached.

Would you try your code on jruby 1.5.0.dev? The latest version is available to download from http://ci.jruby.org/snapshots/.

Show
Yoko Harada added a comment - I think the memory leak discussed here doesn't happen on the latest JRuby version. I watched heap usage while running attached file, MemoryLeak.java, which is the same code displayed here. I also attached the heap usage graph generated by JConsole. The output from jstat was: S0 S1 E O P YGC YGCT FGC FGCT GCT 0.00 0.00 30.60 65.93 93.41 348 0.254 1 0.044 0.298 0.00 29.38 0.00 65.93 93.42 501 0.362 1 0.044 0.406 30.48 0.00 72.04 65.93 93.42 654 0.469 1 0.044 0.513 0.00 29.38 0.00 65.93 93.42 809 0.566 1 0.044 0.610 0.00 29.38 0.00 65.93 93.42 963 0.672 1 0.044 0.717 34.58 0.00 0.00 65.93 93.42 1118 0.772 1 0.044 0.817 0.00 29.38 29.95 65.93 93.42 1271 0.875 1 0.044 0.919 34.58 0.00 0.00 65.93 93.42 1426 0.979 1 0.044 1.023 34.58 0.00 59.36 65.93 93.42 1580 1.084 1 0.044 1.128 34.58 0.00 88.28 65.93 93.42 1735 1.183 1 0.044 1.228 My environment is: electra:Birch yoko$ java -version java version "1.5.0_22" Java(TM) 2 Runtime Environment, Standard Edition (build 1.5.0_22-b03-333-9M3125) Java HotSpot(TM) Client VM (build 1.5.0_22-147, mixed mode, sharing) electra:jruby~main yoko$ jruby -v jruby 1.5.0.dev (ruby 1.8.7 patchlevel 174) (2010-02-24 944db04) (Java HotSpot(TM) Client VM 1.5.0_22) [i386-java] I ran the attached program as in below: java -cp /Users/yoko/DevSpace/jruby~main/lib/jruby.jar:/Users/yoko/DevSpace/jruby~main/build_lib/livetribe-jsr223-2.0.6.jar:build redbridge.MemoryLeak Generating garbage for 5 mins... Garbage generated, hanging... I also ran the program in scripting-ruby.zip. It went "Creating job number 99999" and said "done." The heap usage curve was quite similar to the one I attached. Would you try your code on jruby 1.5.0.dev? The latest version is available to download from http://ci.jruby.org/snapshots/.
Hide
Permalink
Yoko Harada added a comment -

Oops, spaces were crushed. Here's output from jstat:

 
  S0     S1     E      O      P     YGC     YGCT    FGC    FGCT     GCT   
  0.00   0.00  30.60  65.93  93.41    348    0.254     1    0.044    0.298
  0.00  29.38   0.00  65.93  93.42    501    0.362     1    0.044    0.406
 30.48   0.00  72.04  65.93  93.42    654    0.469     1    0.044    0.513
  0.00  29.38   0.00  65.93  93.42    809    0.566     1    0.044    0.610
  0.00  29.38   0.00  65.93  93.42    963    0.672     1    0.044    0.717
 34.58   0.00   0.00  65.93  93.42   1118    0.772     1    0.044    0.817
  0.00  29.38  29.95  65.93  93.42   1271    0.875     1    0.044    0.919
 34.58   0.00   0.00  65.93  93.42   1426    0.979     1    0.044    1.023
 34.58   0.00  59.36  65.93  93.42   1580    1.084     1    0.044    1.128
 34.58   0.00  88.28  65.93  93.42   1735    1.183     1    0.044    1.228
Show
Yoko Harada added a comment - Oops, spaces were crushed. Here's output from jstat: 
 
  S0     S1     E      O      P     YGC     YGCT    FGC    FGCT     GCT   
  0.00   0.00  30.60  65.93  93.41    348    0.254     1    0.044    0.298
  0.00  29.38   0.00  65.93  93.42    501    0.362     1    0.044    0.406
 30.48   0.00  72.04  65.93  93.42    654    0.469     1    0.044    0.513
  0.00  29.38   0.00  65.93  93.42    809    0.566     1    0.044    0.610
  0.00  29.38   0.00  65.93  93.42    963    0.672     1    0.044    0.717
 34.58   0.00   0.00  65.93  93.42   1118    0.772     1    0.044    0.817
  0.00  29.38  29.95  65.93  93.42   1271    0.875     1    0.044    0.919
 34.58   0.00   0.00  65.93  93.42   1426    0.979     1    0.044    1.023
 34.58   0.00  59.36  65.93  93.42   1580    1.084     1    0.044    1.128
 34.58   0.00  88.28  65.93  93.42   1735    1.183     1    0.044    1.228
Hide
Permalink
Lars J. Nilsson added a comment -

Yes, JRuby 1.5.dev seems to have fixed it.

Btw, for reference, my environment is:

java version "1.6.0_0"
OpenJDK Runtime Environment (IcedTea6 1.6) (mandriva-0.20.b16.11mdv2010.0-x86_64)
OpenJDK 64-Bit Server VM (build 14.0-b16, mixed mode)

/Lars J. Nilsson
www.cubeia.com

Show
Lars J. Nilsson added a comment - Yes, JRuby 1.5.dev seems to have fixed it. Btw, for reference, my environment is: 
java version "1.6.0_0"
OpenJDK Runtime Environment (IcedTea6 1.6) (mandriva-0.20.b16.11mdv2010.0-x86_64)
OpenJDK 64-Bit Server VM (build 14.0-b16, mixed mode)
/Lars J. Nilsson www.cubeia.com
Hide
Permalink
Hiro Asari added a comment -

Resolving the ticket based on Lars' confirmation on February 25.

Show
Hiro Asari added a comment - Resolving the ticket based on Lars' confirmation on February 25.

People

Vote (1)
Watch (4)

Dates

  • Created:
    Updated:
    Resolved:
Atlassian JIRA (v4.4.3#663-r165197) | Report a problem
Powered by a free Atlassian JIRA open source license for Codehaus. Try JIRA - bug tracking software for your team.