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.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
