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
