On 30.04.2017 12:53, Rick McGuire wrote:
> I want to verify something first. In this scenario, Rexx code makes a call to
> a Java method (i.e.,
> the parser) which then makes a lot of callbacks all on the same thread?
Yes.
> If so, then I think I might see where the problem could be. The code that
> handles nested thread
> attaches (that is, attaching to a thread that already exists) appears to hold
> on to any allocated
> objects until it returns to the original exit point (in your case, the
> initial call to the parser).
>
> This may take a little while to figure out the details of a fix, but I at
> least know where to
> start. You might want to open a bug indicating there appears to be an
> AttachThread()/DetachThread() memory leak.
Opened a bug: <https://sourceforge.net/p/oorexx/bugs/1445/>.
---rony
>
> On Sun, Apr 30, 2017 at 6:38 AM, Rony G. Flatscher <rony.flatsc...@wu.ac.at
> <mailto:rony.flatsc...@wu.ac.at>> wrote:
>
> Having slept I went over the debug statements, just to learn that I
> concluded wrongly
> yesterday: the reference decreases did not come from the Rexx objects
> with uninits, but from
> the Java side! :(
>
> With new debug statements on the Rexx side (in the destructores) it is
> clear that no proxy
> Rexx object turns into garbage before the program gets interrupted with a
> syntax error.
>
> Will start over analyzing the codepaths, creating debug programs and
> report back, once I am
> done, which might take a day or two.
>
> ---rony
>
>
> On 29.04.2017 21:53, Rick McGuire wrote:
>>
>>
>> On Sat, Apr 29, 2017 at 3:43 PM, Rony G. Flatscher
>> <rony.flatsc...@wu.ac.at
>> <mailto:rony.flatsc...@wu.ac.at>> wrote:
>>
>> The class object (for the BSF class and also its subclasses) is
>> (get) created in the
>> BSF.CLS package, which gets required. So it (and its subclasses)
>> should get created only
>> once in this test case.
>>
>> The ooRexx peer objects are instances of the .BSF class, which
>> defines an uninit method.
>>
>> Ad interpreter safepoints:
>>
>> * in this case there is a pending external Rexx function call that
>> kicks of the SAX
>> parser's parsing and only will return after the SAX parser
>> concluded its work,
>> * in the meantime each callback from the SAX parser will cause a
>> call via JNI to Rexx,
>> where each such callback will do an AttachThread() in native
>> code and before
>> returning a DetachThread().
>>
>> The uninits run, so these interpreter safepoints should be reached.
>>
>> The return from the ooRexx code at the end of the event call is one
>> safepoint, but the
>> arguments you passed will still be protected at this point. However,
>> these objects will not
>> be processed until the next time a garbage collection is required and
>> then not until the next
>> uninit point is hit.
>>
>>
>>
>> ---
>>
>> Maybe one more thing: the ooRexx peer objects that get created in
>> native code are stored
>> in a RexxArray object as they server as arguments for the
>> SendMessage() function. So I
>> assume (pure speculation!) that first the RexxArray object needs to
>> get destroyed in
>> order for its contained objects to become eligible for destruction.
>> Maybe that explains
>> why the Rexx peer objects currently do not get their uninits run at
>> a much faster pace.
>>
>>
>> I doubt this causes much of the delay, since these objects don't get
>> moved to the uninit
>> queue until the next time it is necessary to run the garbage collector.
>> It is highly unlikely
>> that more than a few objects would be affected by this, but you might
>> give it a try and see
>> what happens.
>>
>> Rick
>>
>>
>> ---rony
>>
>>
>>
>> On 29.04.2017 21:32, Rick McGuire wrote:
>>> Running the garbage collector will not force the uninit methods to
>>> be run. When the
>>> garbage collector runs, any newly dead objects with uninit methods
>>> are marked as being
>>> ready to have the uninit method run. At some later time, when the
>>> interpreter is at a
>>> safe point, then the objects with pending uninit methods will be
>>> processed. These are
>>> major boundaries such as return from a method or call or thread
>>> termination.
>>>
>>> Since you are creating class objects, things can get delayed even
>>> further since the
>>> class object will not become "dead" until all of its instances are
>>> first "dead". It then
>>> gets moved to the uninit queue for processing.
>>>
>>> Rick
>>>
>>> On Sat, Apr 29, 2017 at 3:11 PM, Rony G. Flatscher
>>> <rony.flatsc...@wu.ac.at
>>> <mailto:rony.flatsc...@wu.ac.at>> wrote:
>>>
>>> Today, I have started to analyze the code-paths through
>>> BSF4ooRexx (Java, c++,
>>> ooRexx-package BSF.CLS).
>>>
>>> As I have not found any "obvious" cause for the observed
>>> behaviour yet, I have
>>> started to analyse the changes in the Java registry (that I
>>> have full control of).
>>>
>>> Maybe first a sketch, how Java objects get proxied by ooRexx
>>> objects:
>>>
>>> * a Java object that is to be sent to ooRexx as a return or
>>> argument value will
>>> get stored together with a reference counter in a Java
>>> registry (using a
>>> ConcurrentHashMap), the index is a string which will get
>>> passed on to Rexx
>>> instead of the Java object,
>>> * the Rexx side will create an instance of the class .BSF (or
>>> a subclass of it)
>>> supplying the Java object's index string which is used as
>>> the objecname for the
>>> ooRexx peer object
>>> o The BSF class has a destructor method (uninit) which
>>> will cause a call to
>>> the Java side to reduce the Java object's reference
>>> counter; if the Java
>>> reference counter drops to 0 the Java object will be
>>> removed from the Java
>>> registry
>>>
>>> Running the SAX-example serving as the test case until 250
>>> startElement
>>> SAX-callbacks (each callback from Java to Rexx will cause an
>>> AttachThread(),
>>> creating the ooRexx peer objects for the arguments, sending the
>>> Rexx message, upon
>>> return doing a DetachThread()) have been carried out (in
>>> addition there are plenty
>>> of other SAX-callbacks) and using debug statements for adding
>>> and removing entries
>>> to/from the Java registry, this is what I can observe:
>>>
>>> * the ooRexx destructors run,
>>> * *however* the rate of new ooRexx peer objects that get
>>> created (by Java objects
>>> that are sent to Rexx) is much higher than the rate of
>>> ooRexx peer objects that
>>> get garbage collected by ooRexx, which causes a continuous
>>> increase in Rexx
>>> objects over time
>>> o indeed, the ooRexx peer objects get destroyed
>>> eventually, causing the Java
>>> refcounters to be decreased
>>> + it seems that not all ooRexx peer objects that have
>>> turned into garbage
>>> get destroyed in the garbage collection runs
>>> o still (hence), the amount of ooRexx peer objects
>>> increases quickly at
>>> runtime as the flux of callbacks from Java continues
>>> * at the end of the program (in this case forcing an error to
>>> stop it by issuing a
>>> 'say 1/0') all uninits run the reference counters on the
>>> Java objects in the
>>> Java registry drop to 0!
>>>
>>> Is there a way in ooRexx to have the garbage collector be run
>>> (like in Java's
>>> System.gc() or Runtime.getRuntime.gc())?
>>>
>>> Such a possibility might help to debug/tame this "run-away"
>>> scenario.
>>>
>>> ---rony
>>>
>>>
>>>
>>> On 27.04.2017 16:56, Rony G. Flatscher wrote:
>>>>
>>>> Thank you! Will report back, once I concluded the analysis,
>>>> which may take a while.
>>>>
>>>> ---rony
>>>>
>>>>
>>>> On 27.04.2017 16:53, Rick McGuire wrote:
>>>>> The memory manager will force any pending uninits to be run
>>>>> before it gives up and
>>>>> issues the out of resources error messages. I really suspect
>>>>> something in the way
>>>>> your code is creating the proxies and tracking them is
>>>>> preventing the objects from
>>>>> being identified as dead objects, so these objects will just
>>>>> keep accumulating.
>>>>> The more live objects locked in memory, the longer a GC cycle
>>>>> will take because
>>>>> there is a larger live set to mark.
>>>>>
>>>>> Rick
>>>>>
>>>>> On Thu, Apr 27, 2017 at 10:34 AM, Rony G. Flatscher
>>>>> <rony.flatsc...@wu.ac.at
>>>>> <mailto:rony.flatsc...@wu.ac.at>> wrote:
>>>>>
>>>>> Further information, using the initial e-mail to keep all
>>>>> relevant information
>>>>> in one e-mail.
>>>>>
>>>>> Today I uninstalled the 32-bit ooRexx 5.0beta and
>>>>> installed the 64-bit ooRexx
>>>>> 5.0beta (both from SourceForge, downloaded February 4th
>>>>> 2017).
>>>>>
>>>>> This time the program ran successfully to the end:
>>>>>
>>>>> * there were more than 247,000 XML elements processed
>>>>> o as already mentioned this may translate into
>>>>> million(s) call backs
>>>>> from Java to Rexx as all SAX events will cause
>>>>> callbacks to Rexx
>>>>> + some of these callbacks carry Java objects as
>>>>> arguments which will
>>>>> get wrapped as a peer ooRexx object
>>>>> (ultimately an instance of the
>>>>> class .BSF that has an uninit method
>>>>> defined), namely the Java
>>>>> types: "char[]", "Attributes", "Local" from
>>>>> the callbacks
>>>>>
>>>>> <https://docs.oracle.com/javase/7/docs/api/org/xml/sax/ContentHandler.html
>>>>>
>>>>> <https://docs.oracle.com/javase/7/docs/api/org/xml/sax/ContentHandler.html>>
>>>>> + there are no return values (all callbacks are
>>>>> defined to be void)
>>>>>
>>>>> * it took a total of 2:37 hours to SAX-parse a 10MB XML
>>>>> file,
>>>>> o the SAX-parsing was over after 1:45 hours
>>>>> + the program constantly slowed down and in
>>>>> between paused for a
>>>>> while (which got longer and longer over time)
>>>>> o after the SAX-parseing was over the Rexx program
>>>>> needed another 0:52
>>>>> hours to complete
>>>>> + speculating/assuming that in this time all
>>>>> the uninits got
>>>>> executed (which is fine)
>>>>>
>>>>> * it consumed 8.7GB of memory
>>>>> o ProcessExplorer reports a
>>>>> + Physical Memory "PeekWorking Set" of
>>>>> 8.795.796 K
>>>>> + Virtual Memory "Virtual Size" of 13.404.424 K
>>>>> with "Peak Private
>>>>> Bytes" of 9.138.664 K
>>>>>
>>>>> * it used 24% of the CPU over all 2:37 hours
>>>>> o ProcessExplorer reports a
>>>>> + "Kernel Time" of 0:01:10.184
>>>>> + "User Time" of 2.32.57.960
>>>>> + "Total Time" of 2:34:08.144
>>>>> + "Cycles": 23.898.290.997.693
>>>>>
>>>>> Will check the BSF4ooRexx call and code paths.
>>>>>
>>>>> ---rony
>>>>>
>>>>>
>>>>>
>>>>> On 26.04.2017 20:28, Rony G. Flatscher wrote:
>>>>>>
>>>>>> A student is using BSF4ooRexx to parse a huge XML file
>>>>>> using Java's SAX parser.
>>>>>>
>>>>>> The SAX (simple API for XML) works with a callback
>>>>>> concept. In order to be
>>>>>> eligible for these SAX callbacks the ContentHandler
>>>>>> interface
>>>>>>
>>>>>> <https://docs.oracle.com/javase/7/docs/api/org/xml/sax/ContentHandler.html>
>>>>>>
>>>>>> <https://docs.oracle.com/javase/7/docs/api/org/xml/sax/ContentHandler.html>
>>>>>> must be implemented, which the Rexx program does with
>>>>>> the help of BSF4ooRexx.
>>>>>>
>>>>>> As a result each single SAX event will cause an
>>>>>> appropriate Rexx message to
>>>>>> be generated and dispatched. The Rexx message is named
>>>>>> after the
>>>>>> ContentHandler method name and will receive all
>>>>>> arguments documented there.
>>>>>> All arguments are processed in native code, a Rexx array
>>>>>> object will get
>>>>>> created from the Java arguments.
>>>>>>
>>>>>> This works and was presented on one of the International
>>>>>> Rexx symposiums and
>>>>>> has become part of my lecture using Java camouflaged as
>>>>>> ooRexx with the help
>>>>>> of BSF4ooRexx. Here is a link to the symposium which
>>>>>> contains links to the
>>>>>> slides: <http://rexxla.org/events/2013/schedule.html>
>>>>>> <http://rexxla.org/events/2013/schedule.html>.
>>>>>>
>>>>>> Now, a student is in the need to parse a rather huge XML
>>>>>> file (10 MB) and
>>>>>> uses the SAX parser. She always hits the Rexx "Error 5:
>>>>>> System resources
>>>>>> exhausted"! I asked her to come up with a very small
>>>>>> program to demonstrate
>>>>>> the error and I am able to reproduce it reliably!
>>>>>>
>>>>>> Here is the rather short Rexx program:
>>>>>> --- #!/usr/bin/rexx parse arg xmlFile if xmlFile="" then
>>>>>> XMLFile="..\LB-HB.onlb" if sysFileExists(xmlFile)=.false
>>>>>> then do say "File"
>>>>>> pp(xmlFile) "does not exist, aborting." exit -1 end
>>>>>> rexxObject=.saxHandler~new();
>>>>>>
>>>>>> javaProxy=BSFCreateRexxProxy(rexxObject,,"org.xml.sax.ContentHandler")
>>>>>>
>>>>>> parser=bsf.loadClass("org.xml.sax.helpers.XMLReaderFactory")~createXMLReader
>>>>>> parser~setContentHandler(javaProxy) eh=.errorHandler~new
>>>>>> javaEH=BsfCreateRexxProxy(eh,,"org.xml.sax.ErrorHandler")
>>>>>> parser~setErrorHandler(javaEH) signal on syntax
>>>>>> start=.dateTime~new say
>>>>>> pp(start)": start of parsing" parser~parse(XMLFile)
>>>>>> end=.dateTime~new say
>>>>>> pp(end)": end of parsing" say "done, needed:"
>>>>>> pp(end-start) exit syntax: say
>>>>>> "error at" rexxObject~nrOfElements "element"
>>>>>> co=condition('o') say
>>>>>> ppCondition2(co) ::requires "BSF.CLS" /* get the Java
>>>>>> support */ ::requires
>>>>>> "rgf_util2.rex" ::CLASS "SaxHandler" -- a Rexx content
>>>>>> handler
>>>>>> ("org.xml.sax.ContentHandler") ::attribute nrOfElements
>>>>>> ::METHOD init
>>>>>> --ooRexx constructor expose nrOfElements nrOfElements=0
>>>>>> ::METHOD startElement
>>>>>> expose nrOfElements USE ARG uri, localName, qName,
>>>>>> attributes nrOfElements+=1
>>>>>> if nrOfElements//1000=0 then say nrOfElements "elements
>>>>>> so far ..." ::METHOD
>>>>>> characters -- the callback method for characters (text)
>>>>>> USE ARG charArray,
>>>>>> start, length ::METHOD endElement USE ARG uri,
>>>>>> localName, qName, attributes
>>>>>> ::method unknown ::class ErrorHandler ::method unknown
>>>>>> use arg methName,
>>>>>> argArray exception=argArray[1]s .error~say(methName": "
>>>>>> "line="exception~getLineNumber
>>>>>> ",col="exception~getColumnNumber": "
>>>>>> pp(exception~getMessage)) ---
>>>>>> As you might see, there is nothing "special" going on
>>>>>> here, other than being
>>>>>> able to supply a Rexx object as the callback object for
>>>>>> the Java implemented
>>>>>> SAX parser! It seems that running all these callback
>>>>>> from Java to Rexx will
>>>>>> cause eventually that ooRexx gets exhausted of system
>>>>>> resources. While
>>>>>> running the program it can be observed that from time to
>>>>>> time there are
>>>>>> little lags as if some garbage collecting takes place.
>>>>>> Eventually the error 5
>>>>>> is thrown, while executing in native code:
>>>>>>
>>>>>> result_obj=rtc->SendMessage(ro, c_msg, ra); // with
>>>>>> arguments
>>>>>>
>>>>>> Please note that the following error message only gives
>>>>>> the numbers of XML
>>>>>> elements that the SAX parser reported. In reality, *all*
>>>>>> callbacks are
>>>>>> carried out from Java to Rexx, the unprocessed ones will
>>>>>> be intercepted by
>>>>>> the Rexx UNKNOWN method. So there is a flurry of context
>>>>>> switches and
>>>>>> creation of Rexx array objects for the arguments and the
>>>>>> like. Here is the
>>>>>> error message on my system.
>>>>>> --- 83000 elements so far ... 84000 elements so far ...
>>>>>> error at 84926
>>>>>> element [ADDITIONAL] =[an Array (2 items)
>>>>>> id#_-1457160369]
>>>>>> ["BSF4ooRexx/routine/BSF(), error 3: Java exception
>>>>>> occurred:
>>>>>> [org.rexxla.bsf.engines.rexx.RexxException:
>>>>>> BSF4ooRexx/routine/jniRexxSendMessageToRexxObject(),
>>>>>> error 4:" || "0A"x || "
>>>>>> *-* Compiled method ""OBJECTNAME="" with scope
>>>>>> ""Object""." || "0A"x ||
>>>>>> "Error 5 running C:\Program Files
>>>>>> (x86)\BSF4ooRexx\BSF.CLS line 2644: System
>>>>>> resources exhausted." || "0A"x || "Error 5.0: message
>>>>>> n/a]"]
>>>>>> [org.rexxla.bsf.engines.rexx.RexxException@182d820
>>>>>> id#_-1478994985] [CODE]
>>>>>> =[40.900] [CONDITION] =[SYNTAX] [DESCRIPTION]=[]
>>>>>> [ERRORTEXT] =[Incorrect call
>>>>>> to routine.] [INSTRUCTION]=[SIGNAL] [MESSAGE]
>>>>>> =["BSF4ooRexx/routine/BSF(),
>>>>>> error 3: Java exception occurred:
>>>>>> [org.rexxla.bsf.engines.rexx.RexxException:
>>>>>> BSF4ooRexx/routine/jniRexxSendMessageToRexxObject(),
>>>>>> error 4:" || "0A"x || "
>>>>>> *-* Compiled method ""OBJECTNAME="" with scope
>>>>>> ""Object""." || "0A"x ||
>>>>>> "Error 5 running C:\Program Files
>>>>>> (x86)\BSF4ooRexx\BSF.CLS line 2644: System
>>>>>> resources exhausted." || "0A"x || "Error 5.0: message
>>>>>> n/a]."] [PACKAGE] =[a
>>>>>> Package id#_-2109388833] [POSITION] =[25] [PROGRAM]
>>>>>> =[F:\tmp\orx\kirisits\20170425\SAX_noAlerts.rxj]
>>>>>> [PROPAGATED] =[1] [RC] =[40]
>>>>>> [STACKFRAMES]=[a List (4 items) id#_-1467321073] [ *-*
>>>>>> Compiled routine
>>>>>> "BSF". id#_-1939043649] [ 1811 *-* res=BSF( "invoke",
>>>>>> "com.sun.org.apache.xerces.int
>>>>>>
>>>>>> <http://com.sun.org.apache.xerces.int>ernal.parsers.SAXParser@117ae12",
>>>>>> "PARSE" , a.1 ) id#_-1938526417] [ 1813 *-* interpret
>>>>>> code ")" -- execute
>>>>>> this dynamically created Rexx string id#_-1937397361] [
>>>>>> 25 *-*
>>>>>> parser~parse(XMLFile) id#_-1936143753] [TRACEBACK] =[a
>>>>>> List (4 items)
>>>>>> id#_-1458379065] [ *-* Compiled routine "BSF".] [ 1811
>>>>>> *-* res=BSF( "invoke",
>>>>>> "com.sun.org.apache.xerces.int
>>>>>>
>>>>>> <http://com.sun.org.apache.xerces.int>ernal.parsers.SAXParser@117ae12",
>>>>>> "PARSE" , a.1 )] [ 1813 *-* interpret code ")" --
>>>>>> execute this dynamically
>>>>>> created Rexx string] [ 25 *-* parser~parse(XMLFile)] ---
>>>>>> The traceback points to the invocation of the SAX parser
>>>>>> from Rexx which only
>>>>>> returns upon completion of the Java parse method, or in
>>>>>> this case when an
>>>>>> error interrupts the program. --- So now my
>>>>>> question/request: how to debug
>>>>>> this problem/error? How can I get more information from
>>>>>> the ooRexx
>>>>>> interpreter? How can one determine what kind of "system
>>>>>> resources" got
>>>>>> exhausted and what the cause would be? Can one e.g.
>>>>>> determine how many Rexx
>>>>>> objects there are and how many are dead, in the need of
>>>>>> getting garbage
>>>>>> collected? In this case whenever (on each SAX callback)
>>>>>> the Java side invokes
>>>>>> the native code which then sends the message to the Rexx
>>>>>> object there will be
>>>>>> an AttachThread() followed by a DetachThread(). Please
>>>>>> advise! ---rony
------------------------------------------------------------------------------
Check out the vibrant tech community on one of the world's most
engaging tech sites, Slashdot.org! http://sdm.link/slashdot
_______________________________________________
Oorexx-devel mailing list
Oorexx-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/oorexx-devel
