On Sat, Apr 29, 2017 at 3:43 PM, Rony G. Flatscher <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> 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
>> - 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
>> - 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
>> - 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> 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
>>> - 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/Conte
>>> ntHandler.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,
>>> - 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)
>>> - 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
>>> - 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
>>> - 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/Conte
>>> ntHandler.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.internal.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.internal.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
>
>
------------------------------------------------------------------------------
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
