[Bsf4oorexx-bugs] [ bsf4oorexx-Bugs-3525814 ] Excessive memory use / possible memory leak

[SourceForge.net <no...@so...>]

Bugs item #3525814, was opened at 2012-05-11 05:48
Message generated for change (Comment added) made by orexx
You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=1660873&aid=3525814&group_id=400586

Please note that this message will contain a full copy of the comment thread,
including the initial issue submission, for this request,
not just the latest update.
Category: None
Group: None
Status: Open
Resolution: None
Priority: 5
Private: No
Submitted By: Erik Duijs (eduijs)
Assigned to: Nobody/Anonymous (nobody)
Summary: Excessive memory use / possible memory leak

Initial Comment:
There seems to be a memory leak in BSF4ooRexx, leading to excessive memory use and eventual OOMEs.

This is demonstrated in the attached example program MemLeak.java
If you compile and run this program, it will fill up memory until an OOME is thrown while there seems to be no reason for that in the Rexx part and the Java part of the example.

Having analyzed a heap dump, it seems that each java method invocation from rexx is held but not freed in the JNI part of BSF4ooRexx.
In the case of this example program, this leads to hundreds of thousands of instances of the Strings "invoke", "bsf4rexx.test.MemLeak$1@863399" and "getValue", but also its return value "42" as JNI-local references.

----------------------------------------------------------------------

>Comment By: Rony G. Flatscher (orexx)
Date: 2012-05-24 12:52

Message:
After a lot of peeking and poking it seems that the problem is Java-based
and as follows:

if one creates jstrings (or jobjects for that matter) and assigns them to
arrays the Java garbage collector seems to not be able anymore to identify
the Java objects that turned to garbage. Given the JNI documentation and
the brief information on local references, this problem should not occur.

The solution is to assign each jstring or jobject to a local variable and
after assigning it to an array do a DeleteLocalRef() on them. 

In the course of adding DeleteLocalRef() I also addressed all local Java
object variables and explicitly do a DeleteLocalRef(), although according
to the docs this should not be necessary. 

Re-running your test-script, even after 30 million (!) invocations of BSF()
the Java heap remained stable.

@Eirk: could you try the fix for your test programs and let us know ASAP if
the problem went away for you as well? If so, I would create a new beta of
BSF4ooRexx to test this version another two weeks or so. Just replace your
32-bit Windows version of "BSF4ooRexx.dll" with the current one on
Sourceforge (trunk\bsf4oorexx.dev\source_cc\32\BSF4ooRexx.dll: this is the
only newly built library; you could build your own version by checking out
trunk\bsf4oorexx.dev\source_cc\BSF4ooRexx.cc from Sourceforge).


----------------------------------------------------------------------

Comment By: Rony G. Flatscher (orexx)
Date: 2012-05-22 12:24

Message:
OK, had a few glimpses at the codepaths and tried in between all kind of
changes (like Java's DeleteLocalRefs(), Java's ReleaseByteArrayElements(),
ooRexx' ReleaseLocalReference()) in the BSF() external function and the
respective JNU_-functions where the arguments are handled from Rexx to Java
and vice versa. 

However, these initial peeks and pokes have not changed the overall
behavior, such that I will have to look into this more thoroughly over the
weekend, time permitting.

N.B.: Looking at the heap representation of visualvm it is interesting to
note:
- there are unreferenced buf[]
- there are char[] (matching appr. the number of buf[]), that are
referenced by String, which themselves are referenced by String[]
- all String[] seem to not be referenced

AFAICT there are no local references on buf[], char[], String, String[] on
the Java and native side such that all that space should be reclaimable by
Java's GC.


----------------------------------------------------------------------

Comment By: Erik Duijs (eduijs)
Date: 2012-05-19 10:10

Message:
@Rony

I have used the memory profiling tool in visualvm (it's in the JDK) for my
analysis. 

After letting the test program run for a while, I found an enormous amount
of String[] JNI-local references which I believe contain the input
parameters for the bsf() method. All those Strings seemed to be copies of
the same values (not just references to the same Strings).
Also manually triggering GC from visual-vm when pausing the test program
didn't seem to free up any of these specific references.

I don't completely rule out that I'm barking up the wrong tree here because
I don't exactly do this kind of analysis in a JNI context every day :), but
it looked quite suspicious to me.

Let me know if there's something more I can do to help.

Cheers,
Erik

----------------------------------------------------------------------

Comment By: Rony G. Flatscher (orexx)
Date: 2012-05-19 08:28

Message:
@Erik: just ran with JDK 1.6

  java -agentlib:hprof=heap=all,format=b,file=java.hprof MemLeak

and then 

  jhat java.hprof

Cannot find the reported abmysal use of local references on the Java/JNI
side. As I rarely use that tool it may be the case that I am not
looking/querying in the right corner. However, querying in OQL for the Java
string "invoke" or "INVOKE" does not return any references:

   select s.value.toString() from java.lang.String s 
       where /invoke/(s.value.toString())

Again, it may be the case that I am not using jhat correctly or it is not
the right tool for analyzing this problem. So I was wondering what kind of
heap and heap-analysis tools you were using?

---

P.S.: On Java 1.6 the OOM problem occurs between 750,000 and 760,000
invocations (showing every 10000 cycles in the Rexx loop). Here's the
slightly edited Rexx code of your Java program:

    // @formatter:off
    static final String SCRIPT =
          "bean = bsf('lookupBean', 'mybean')\n"
        + "numeric digits 20\n"
        + "DO i=1 --FOREVER\n"
        + "  r = bsf('invoke', bean, 'getValue')\n"
        + "  if i//10000=0 then say 'i='right(i,20)\n"
        + "END\n";
    // @formatter:on



----------------------------------------------------------------------

Comment By: Rony G. Flatscher (orexx)
Date: 2012-05-19 04:12

Message:
Thank you all for your analysis (and the test program) and also hints for
possible causes! Will look into this ASAP (still being a little bit "under
water"). Maybe if there is a need for discussion, hints, then the
bsf4oorexx developer list is preferable, such that others see what the
problem is or might be. 

(Until I got this bug report I was under the impression that I would follow
the JNI and ooRexx documentations such that this reported behavior could
not occur. Assuming that upon return from the native functions all the
local locks get automatically released. But maybe that is not the case, so
I have to go back to the JNI/ooRexx documentation to double-check.)


----------------------------------------------------------------------

Comment By: jfaucher (jfaucher)
Date: 2012-05-11 07:42

Message:
Rony, don't know if that could be in relation with current defect, but just
in case...
In rexxpg, section 9.5, I noticed that :
<<
sometimes it is desirable to remove the local API context protection from
an object. For example, if you use the ArrayAt() API to iterate through all
of the elements of an Array, each object ArrayAt() returns will be added to
the API context’s protection table. There is a small overhead associated
with each protected reference, so iterating through a large array would
accumulate that overhead for each array element. Using
ReleaseLocalReference() on an object reference you no longer require will
remove the local lock, and thus limit the overhead.
>>

Depending on the life-duration of the associated context, we may have this
problem. Or not.

----------------------------------------------------------------------

You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=1660873&aid=3525814&group_id=400586