From: SourceForge.net <no...@so...> - 2010-09-08 04:42:27
|
Bugs item #2863643, was opened at 2009-09-21 10:08 Message generated for change (Comment added) made by miesfeld You can respond by visiting: https://sourceforge.net/tracker/?func=detail&atid=684730&aid=2863643&group_id=119701 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: APIs Group: v4.0.1 >Status: Closed Resolution: Fixed Priority: 5 Private: No Submitted By: Rony G. Flatscher (orexx) Assigned to: Rick McGuire (bigrixx) Summary: Multithreading problems with ooRexx Initial Comment: Stupidly, the limit for uploaded files is set to 256KB, hence am not able to supply it (and also: stupid Sourceforge will make lose all the supplied text describing the problem when reporting such "errors", unbelievable user-adverse !). :-( So here goes the next take... As reported in the developer list I have been experiencing problems with BSF4Rexx in situations for weeks, where multithreading is heavily employed. In order to isolate the problem I tried to come up with an example code that does not need to use BSF4Rexx, removing that part of the complexity from the table. Here yesterday's e-mail on the developer list with a URL where the example can be found as it is *impossible to upload the zip-archive to Sourceforge!*: ------------- cut here ------------------ Here is the URL where you can get the zip archive: <http://wi.wu.ac.at/rgf/tmp/ooRexx/de_bug/>. ---rony Rony G. Flatscher wrote: > > "Played" around all the weekend, trying to create a test case which would cause an exception in the context of employing multithreading heavily, without BSF4Rexx and Java. > > Finally, after quite some time, I was "lucky" to get the following call trace: > > > rexx.dll!RexxBehaviour::isPrimitive() Line 101 + 0xa bytes C++ > rexx.dll!RexxInternalObject::isBaseClass() Line 175 C++ > rexx.dll!RexxObject::requestString() Line 1132 + 0x8 bytes C++ > rexx.dll!REQUEST_STRING(RexxObject * object=0x7f0f28e0) Line 277 + 0x24 bytes C++ > rexx.dll!ObjectToStringValue(RexxThreadContext_ * c=0x7eeed024, _RexxObjectPtr * o=0x7f0f28e0) Line 971 + 0x8 bytes C++ > TestThreadedExecution.exe!RexxThreadContext_::ObjectToStringValue(_RexxObjectPtr * o=0x7f0f28e0) Line 1026 C++ > TestThreadedExecution.exe!MyThreadFunction(void * lpParam=0x0015d5c0) Line 261 + 0xc bytes C++ > kernel32.dll!7c80b729() > [Frames below may be incorrect and/or missing, no symbols loaded for kernel32.dll] > rexx.dll!RexxMemory::holdObject(RexxInternalObject * obj=0x0015d5c0) Line 1617 C++ > > > Here's the exception: > > > The thread 'Win32 Thread' (0x584) has exited with code 0 (0x0). > Unhandled exception at 0x10017f8a (rexx.dll) in TestThreadedExecution.exe: 0xC0000005: Access violation reading location 0x000000d2. > > > It was necessary to more or less come up with the same architecture as with BSF4Rexx, before I hit this (but had to run the program a couple of times): > > * a C-program that creates a Rexx interpreter instance (using it to create an array object that will be passed on to add the tid-value) and spins off 59 threads, in which each one creates another Rexx interpreter instance which is then used to run a Rexx program that spins off 29 Rexx threads; in the Rexx programs an external routine is called to return the TID to them. > * main() sets up the parameters, one Rexx interpreter instance and calls CreateAndRunThreads(...), which controls the creation of threads; each thread executes the code in MyThreadFunction( ). > > Using the debug version of the 4.0.0 release; the exe and dll is created with debug information as well, such that each accounts for over 400KB, hence uploading the binaries to Sourceforge is not possible, judging from the last such attempts. > > Also, please note, that the exception does not occur reliably, so one may have to re-run the program a couple of times before it may bomb. (Also, I did change the parameters at the beginning of main() a couple of times, recompiled, re-ran the exe a couple of times.) > > Please advise where I should upload the archive to (compiled, sourcecode, Makefile and def-file), which is about 290KB. > > Regards, > > ---rony > > > > Rony G. Flatscher wrote: >> One more observation: changing the Java code for the Java threads to not use the same Rexx interpreter instance (RII) as the previously posted example, but rather create their own RII that then is used to run the submitted Rexx program (which then will spin off Rexx threads), then I get reliably exceptions (all Java threads got created at that point, but no Rexx script has generated any debug output yet), with a stack trace that goes into rexx. >> >> Unfortunately, because of the beginning winter semester, I have barely time to analyze this further, as my planner is now full with University meetings and preparation for classes and the like. So further information from my side may take a couple of days. [The *totally unsubstantiated* "gut feeling" - from weeks of looking at all sort of debug outputs - would be at the moment, that something goes wrong in the AttachThread() or DetachThread() in a heavily multithreaded run-set. Once I debug this new test case, which looks promising just because it reliably fails, I would know more. One test case I plan to create on the weekend is to write a small C++ program that creates 23 threads in which individual RIIs get created, which are then used from the threads to run an adapted Rexx proram, that spins off 27 Rexx threads. With a little "luck" that may exhibit the same behaviour, although the context switches between the Java and Rexx environments would not take place in this case.] >> >> Just posted this for the record, as it may be the case that someone has additional ideas about what I should be looking into while working on this this coming weekend. >> >> ---rony >> >> >> Rony G. Flatscher wrote: >>> Short of an example that would reliably produce an exception in the heavy multithreading scenario, maybe this descritpion of what happens in BSF4Rexx may be helpful: >>> >>> In the context of the testUnits a Rexx program will create an instance of the Java class TestNestedEngines, supplying it the parameters (see below) and RexxProxy objects to follow/interact with. Below is the Java program, followed by the Rexx program that gets invoked. Finally, a brief description of how the Rexx APIs get used. >>> >>> * the following Java program from the BSF4Rexx test unit gets invoked from a Rexx script, supplying as arguments the current BSFManager object which manages one Rexx interpreter instance (RII), a RexxProxy that allows to interact with the testUnit (allowing sending it assert messages), the nrJavaThreads and the nrRexxThreads per Java thread, and a RexxProxy for an ooRexx array, which will get the different thread's thread IDs added (the items in this array will indicate how many threads got invoked): >>> // rgf, 2009-09-10: test execution of Rexx scripts by concurrently creating Rexx scripts >>> >>> package rgf.F_multiThreading; >>> >>> import org.rexxla.bsf.engines.rexx.RexxProxy; >>> >>> import org.apache.bsf.*; // BSF support >>> import java.io.IOException; // exception handling >>> >>> import java.io.File; >>> import java.io.FileReader; >>> import java.util.Vector; >>> >>> /** Test Java program which demonstrates how easy it is to invoke Rexx via BSF. >>> * @author Rony G. Flatscher, 2001-04-27, 2007-09-10, 2009-09-11 >>> */ >>> public class TestNestedEngines { >>> static BSFManager bm=null; // BSFManager of the Rexx instance that invoked this Java program >>> static RexxProxy testUnit=null; // to allow assertions >>> static int nrJavaThreads=0; // determine number of Java threads >>> static int nrRexxThreads=0; // determine number of Rexx threads >>> static String rexxCode=null; // Rexx code to run >>> static RexxProxy rpArray=null; // RexxProxy to allow storing TID in Rexx array object >>> >>> >>> public TestNestedEngines(BSFManager bm, RexxProxy testUnit, int nrJavaThreads, int nrRexxThreads, String rexxCode, RexxProxy rpArray) >>> { >>> // save arguments in attributes >>> TestNestedEngines.bm =bm; >>> TestNestedEngines.testUnit =testUnit; >>> TestNestedEngines.nrJavaThreads =nrJavaThreads; >>> TestNestedEngines.nrRexxThreads =nrRexxThreads; >>> TestNestedEngines.rexxCode =rexxCode; >>> TestNestedEngines.rpArray =rpArray; >>> } >>> >>> >>> /** Creates number of desired threads, runs them. */ >>> public void dispatchRexxScripts() throws Exception >>> { >>> >>> String tmpResult=""; >>> Throwable tmpTh=null; >>> String tmpthreadName=null; >>> >>> // create arrays of needed size >>> Thread t[]=new Thread[nrJavaThreads]; >>> ThreadedJNIRexxStart r[]=new ThreadedJNIRexxStart[nrJavaThreads]; >>> >>> for (int i=0;i<nrJavaThreads; i++) >>> { >>> r[i]=new ThreadedJNIRexxStart(); >>> t[i]=new Thread(r[i]); // create thread >>> r[i].setThreadName(t[i].getName()); >>> t[i].start(); // start execution on own thread >>> } >>> // all got started >>> >>> for (int i=0;i<nrJavaThreads; i++) // join all threads >>> { >>> t[i].join(); >>> } >>> // all are finished >>> >>> } >>> >>> >>> // Runnable inner class >>> static private class ThreadedJNIRexxStart implements Runnable >>> { >>> // define thread local variables >>> private static ThreadLocal tlThrowable = new ThreadLocal(); >>> private static ThreadLocal tlResult = new ThreadLocal(); >>> private static ThreadLocal tlThreadName= new ThreadLocal(); >>> >>> >>> public void run () // invoke ooRexx on its own Java thread >>> { >>> try { >>> String threadName=Thread.currentThread().getName(); >>> >>> rpArray.invoke("APPEND", new Object [] {threadName} ); // save this thread name in supplied RexxProxy array >>> >>> // define arguments for Rexx script >>> Vector args = new Vector(4); >>> args.add(testUnit); >>> args.add(rpArray); >>> args.add(new Integer(nrRexxThreads)); >>> args.add(threadName); >>> >>> // load the Rexx engine for this BSFManager instance >>> BSFEngine rexx = bm.loadScriptingEngine("rexx"); >>> >>> // execute the Rexx script >>> Object result= rexx.apply ("rexx", 0, 0, >>> rexxCode.replaceAll("@threadName", (""+threadName)), >>> null, >>> args); >>> >>> tlResult.set(result); // save result >>> } >>> catch (Throwable th) { >>> tlThrowable.set(th); // save Throwable >>> System.err.println("TestNestedEngines: threadName=["+tlThreadName.get()+"], Throwable=["+th+"]"); >>> th.printStackTrace(); >>> } >>> } >>> >>> public Object getResult() { // getter >>> return tlResult.get(); >>> } >>> >>> public Throwable getThrowable() { // getter >>> return (Throwable) tlThrowable.get(); >>> } >>> >>> public String getThreadName() { // getter >>> return (String) tlThreadName.get(); >>> } >>> >>> public void setThreadName(String threadName) { // setter >>> tlThreadName.set(threadName); >>> } >>> } >>> } >>> >>> * this is the Rexx program, that the Java program executes: it gets the proxied Rexx object for doing direct assertions, but leaves the rpArray RexxProxy object and addresses it as a Java object (the Java side will then forward whatever message and arguments directly to the proxied Rexx object); an instance of .counter is used to count the active Rexx threads (each thread will decrease the counter before returning, such that the counter drops to 0, if all threads ended; here and then one thread may still be pending after three seconds); the main ooRexx program, which runs in the same thread as the Java thread that started it, supplies its TID to the message "work" which it sends to each instance of .ThreadClz. The "work" method does a reply, in the remaining code the supplied TID will be used to attach the Rexx thread to Java using TID's global referenced Java object, but attaching using Java's AttachCurrentThread, creating (and caching) a valid JNIEnv which then is used to interface with Java: >>> use arg rpTestUnit, rpArray, nrThreads, javaThreadName >>> >>> tid=bsfGetTID() -- get this TID >>> testUnit=BsfRexxProxy(rpTestUnit, "ooRexxObject") -- get ooRexx object that gets proxied >>> >>> -- save this thread's TID >>> argArray=bsf.createJavaArrayOf("java.lang.Object", tid) >>> rpArray~invoke("APPEND", argArray) >>> >>> rexxArray=.array~new -- create a new rexxArray for this controller's threads >>> >>> counter=.counter~new -- create a counter object >>> >>> do i=1 to nrThreads >>> counter~increase -- increase the counter >>> -- thread will decrease counter before returning >>> .ThreadClz_using_RexxProxy_Array~new~work(testUnit, tid, i, counter, rpArray, rexxArray, javaThreadName) >>> end >>> >>> call time "Reset" -- reset timer >>> loop while counter~value>0, time("elapsed")<3 -- until no more threads, or over 10seconds >>> call sysSleep .001 -- yield >>> end >>> >>> testUnit~assertEquals(0, counter~value, "active thread counter in Java thread:" javaThreadName) >>> >>> -- this controller created 'nrThreads' threads, check it >>> testUnit~assertEquals(nrThreads, rexxArray~items, "total number of threads:" javaThreadName) >>> >>> >>> ::requires BSF.CLS >>> >>> >>> /* ==================================================================================== */ >>> -- implement a counter that one can increase/decrease >>> ::class counter >>> ::method init -- constructor >>> expose value >>> value=0 -- set attribute >>> forward to (super) -- let superclass initialize >>> >>> ::attribute value -- allow interfacing with the attribute >>> >>> ::method increase -- increase value by 1 >>> expose value >>> value+=1 >>> return value >>> >>> ::method decrease -- decrease value by 1 >>> expose value >>> value-=1 >>> return value >>> >>> >>> >>> /* ==================================================================================== */ >>> -- implement a class with a threaded worker method >>> ::class "ThreadClz_using_RexxProxy_Array" >>> ::method work >>> use arg testUnit, TID, nr, counter, rpArray, rexxArray, javaThreadName >>> reply -- return & create a new thread >>> >>> thisTID=BsfGetTID() >>> testUnit~assertTrue(BsfAttachToTID(TID), "attaching to main TID:" TID", thread #" nr", thisTID="thisTID "running in Java thread named:" javaThreadName) >>> >>> -- have the RexxProxy send the following message to its proxied Rexx object >>> argArray=bsf.createJavaArrayOf("java.lang.Object", thisTID) >>> rpArray~invoke("APPEND", argArray) -- save thisTID >>> rexxArray~append(thisTID) >>> >>> testUnit~assertTrue(BsfDetach(), "detaching from main TID:" TID", thread #" nr", thisTID="thisTID "running in Java thread named:" javaThreadName) >>> counter~decrease >>> return >>> >>> >>> >>> The Java program above will use the passed BSFManager object to get a reference to its RexxEngine instance which represents a unique Rexx interpreter instance (RII). This RII is then used via JNI to dispatch Rexx scripts or to send messages to Rexx objects. In the case where a Rexx script gets dispatched the following happens: >>> >>> * for each created Java thread rexx.apply() will use JNI to run the supplied Rexx program by >>> o defining: rtc->NewRoutine() >>> o running it: rtc->CallRoutine() >>> * the invoked Rexx program will interact with an ooRexx object directly, with a RexxProxy() via Java, i.e. >>> o the RexxProxy Java method "invoke" is invoked supplying a Java array with arguments, >>> o the Java side will excercise the JNI function that allows sending a Rexx object a message: >>> + the native side will do an AttachThread() using the RII, >>> + the Rexx object is retrieved from the RexxProxy cache, >>> + the received Java aguments are unmarshalled, >>> + the ooRexx object gets the message sent (with the arguments, if any), >>> + upon return a DetachThread() is executed, the return value marshalled for Java >>> o the received return value will then returned to the Rexx side where at the JNI-level it gets unmarshalled and returned. >>> >>> If there is anything else I could supply at the moment, please let me know. >>> >>> ---rony ------------------------------------------------------------------------------ Come build with us! The BlackBerry® Developer Conference in SF, CA is the only developer event you need to attend this year. Jumpstart your developing skills, take BlackBerry mobile applications to market and stay ahead of the curve. Join us from November 9-12, 2009. Register now! http://p.sf.net/sfu/devconf _______________________________________________ Oorexx-devel mailing list Oor...@li... https://lists.sourceforge.net/lists/listinfo/oorexx-devel ---------------------------------------------------------------------- Comment By: Mark Miesfeld (miesfeld) Date: 2010-09-07 21:42 Message: The fix for this item was in the 4.0.1 release. ---------------------------------------------------------------------- Comment By: Rick McGuire (bigrixx) Date: 2010-02-22 16:12 Message: Committed revision 5588. 4.0.1 merge ---------------------------------------------------------------------- Comment By: Rick McGuire (bigrixx) Date: 2009-09-24 02:08 Message: This is not the same problem as the one you reported earlier. The stack track indicates you are using BSFRexx in the call, which is not the case in the sample you provided earlier. The problem you opened using the program you provided is fixed in trunk. If you have other issues, then open a new problem report and provide a means of reproducing the problem. Dlo not keep reopening this problem . ---------------------------------------------------------------------- Comment By: Rony G. Flatscher (orexx) Date: 2009-09-24 01:28 Message: Created ooRexx400_5206-x86_32-debug.exe from trunk. Same behaviour. Here a run where I could get the call stack from VStudio: > rexx.dll!SourceLocation::getLineNumber() Line 51 + 0xa bytes C++ rexx.dll!RexxInstruction::getLineNumber() Line 79 + 0x12 bytes C++ rexx.dll!RexxActivation::getContextLineNumber() Line 2511 C++ rexx.dll!RexxActivation::createStackFrame() Line 4272 + 0x22 bytes C++ rexx.dll!RexxActivationFrame::createStackFrame() Line 58 C++ rexx.dll!RexxActivity::createExceptionObject(long errcode=40900, RexxString * description=0x00000000, RexxArray * additional=0x7f3a4f50, RexxObject * result=0x00000000) Line 912 + 0xd bytes C++ rexx.dll!RexxActivity::raiseException(long errcode=40900, RexxString * description=0x00000000, RexxArray * additional=0x7f3a4f50, RexxObject * result=0x00000000) Line 759 + 0x18 bytes C++ rexx.dll!RexxActivity::reportAnException(long errcode=40900, RexxObject * substitution1=0x7f6a4de8) Line 511 C++ rexx.dll!reportException(long error=40900, RexxObject * a1=0x7f6a4de8) Line 159 C++ rexx.dll!RaiseException1(RexxThreadContext_ * c=0x7f4211fc, unsigned int n=40900, _RexxObjectPtr * o1=0x7f6a4de8) Line 1715 C++ BSF4Rexx.dll!RexxThreadContext_::RaiseException1(unsigned int n=40900, _RexxObjectPtr * o=0x7f6a4de8) Line 1284 C++ BSF4Rexx.dll!RexxCallContext_::RaiseException1(unsigned int n=40900, _RexxObjectPtr * o=0x7f6a4de8) Line 2629 C++ BSF4Rexx.dll!BSF_impl(RexxCallContext_ * context=0x085ef9e0, _RexxArrayObject * argArray=0x7f2fc6e8) Line 5200 C++ BSF4Rexx.dll!BSF(RexxCallContext_ * context=0x085ef9e0, ValueDescriptor * arguments=0x085ef9fc) Line 5146 + 0x17 bytes C++ rexx.dll!RexxNativeActivation::callNativeRoutine(RoutineClass * _routine=0x7f12fb68, RexxNativeRoutine * _code=0x7f12fb48, RexxString * functionName=0x7f0a2328, RexxObject * * list=0x7e308c30, unsigned int count=2, ProtectedObject & resultObj={...}) Line 1319 C++ rexx.dll!RexxNativeRoutine::call(RexxActivity * activity=0x7f4211e8, RoutineClass * routine=0x7f12fb68, RexxString * functionName=0x7f0a2328, RexxObject * * argPtr=0x7e308c30, unsigned int count=2, ProtectedObject & result={...}) Line 316 C++ rexx.dll!RoutineClass::call(RexxActivity * activity=0x7f4211e8, RexxString * msgname=0x7f0a2328, RexxObject * * argPtr=0x7e308c30, unsigned int argcount=2, ProtectedObject & result={...}) Line 234 C++ rexx.dll!PackageManager::callNativeRoutine(RexxActivity * activity=0x7f4211e8, RexxString * name=0x7f0a2328, RexxObject * * arguments=0x7e308c30, unsigned int argcount=2, ProtectedObject & result={...}) Line 658 C++ rexx.dll!SystemInterpreter::invokeExternalFunction(RexxActivation * activation=0x7f2a18f0, RexxActivity * activity=0x7f4211e8, RexxString * target=0x7f0a2328, RexxObject * * arguments=0x7e308c30, unsigned int argcount=2, RexxString * calltype=0x7fd5cb00, ProtectedObject & result={...}) Line 272 + 0x17 bytes C++ rexx.dll!RexxActivation::externalCall(RexxString * target=0x7f0a2328, unsigned int _argcount=2, RexxExpressionStack * _stack=0x7f2a19b0, RexxString * calltype=0x7fd5cb00, ProtectedObject & resultObj={...}) Line 2626 + 0x25 bytes C++ rexx.dll!RexxExpressionFunction::evaluate(RexxActivation * context=0x7f2a18f0, RexxExpressionStack * stack=0x7f2a19b0) Line 225 C++ rexx.dll!RexxExpressionMessage::evaluate(RexxActivation * context=0x7f2a18f0, RexxExpressionStack * stack=0x7f2a19b0) Line 97 + 0x1b bytes C++ rexx.dll!RexxInstructionReturn::execute(RexxActivation * context=0x7f2a18f0, RexxExpressionStack * stack=0x7f2a19b0) Line 70 + 0x1b bytes C++ rexx.dll!RexxActivation::run(RexxObject * _receiver=0x7f54f550, RexxString * msgname=0x7fcc4c20, RexxObject * * _arglist=0x00000000, unsigned int _argcount=0, RexxInstruction * start=0x00000000, ProtectedObject & resultObj={...}) Line 521 C++ rexx.dll!RexxCode::run(RexxActivity * activity=0x7f4211e8, RexxMethod * method=0x7f0cbb88, RexxObject * receiver=0x7f54f550, RexxString * msgname=0x7fcc4c20, RexxObject * * argPtr=0x00000000, unsigned int argcount=0, ProtectedObject & result={...}) Line 136 C++ rexx.dll!RexxMethod::run(RexxActivity * activity=0x7f4211e8, RexxObject * receiver=0x7f54f550, RexxString * msgname=0x7fcc4c20, RexxObject * * argPtr=0x00000000, unsigned int count=0, ProtectedObject & result={...}) Line 325 C++ rexx.dll!RexxObject::messageSend(RexxString * msgname=0x7fcc4c20, RexxObject * * arguments=0x00000000, unsigned int count=0, ProtectedObject & result={...}) Line 793 C++ rexx.dll!RexxObject::sendMessage(RexxString * message=0x7fcc4c20, ProtectedObject & result={...}) Line 439 + 0x1b bytes C++ rexx.dll!RexxObject::sendMessage(RexxString * message=0x7fcc4c20) Line 618 C++ rexx.dll!RexxObject::uninit() Line 2238 C++ rexx.dll!UninitDispatcher::run() Line 55 C++ rexx.dll!RexxNativeActivation::run(TrappingDispatcher & dispatcher={...}) Line 1642 C++ rexx.dll!RexxActivity::run(TrappingDispatcher & target={...}) Line 3067 C++ rexx.dll!RexxMemory::runUninits() Line 554 C++ rexx.dll!RexxMemory::checkUninitQueue() Line 199 + 0x18 bytes C++ rexx.dll!RexxActivation::run(RexxObject * _receiver=0x7ef044a8, RexxString * msgname=0x7f29dc38, RexxObject * * _arglist=0x7e308cac, unsigned int _argcount=7, RexxInstruction * start=0x00000000, ProtectedObject & resultObj={...}) Line 558 C++ rexx.dll!RexxActivation::dispatch() Line 377 + 0x33 bytes C++ rexx.dll!RexxActivity::runThread() Line 126 C++ rexx.dll!call_thread_function(void * arguments=0x7f4211e8) Line 63 C++ kernel32.dll!7c80b729() [Frames below may be incorrect and/or missing, no symbols loaded for kernel32.dll] rexx.dll!RexxStack::push(RexxObject * obj=0x00000002) Line 65 C++ 00000118() The thread 'Win32 Thread' (0x1014) has exited with code 0 (0x0). Unhandled exception at 0x00479c7a (rexx.dll) in rexx.exe: 0xC0000005: Access violation reading location 0x00000014. ---- Or, e.g. console output of a run where "only" runtime errors are reported, but no exception: from the codepaths it is impossible that "trheadName" is "null", and "BsfRexxProxy() would get a string that is led-in with "<O>": ... cut (a repetitive list of the following error messages) ... TestNestedEngines: threadName=[null], Throwable=[org.rexxla.bsf.engines.rexx.RexxException: BSF4Rexx/routine/jniRexxRunProgra m(), error 8: 13 *-* testUnit=BsfRexxProxy(rpTestUnit, "ooRexxObject") -- get ooRexx object that gets proxied Error 40 running rexx line 13: Incorrect call to routine Error 40.900: BSF4Rexx/routine/BsfRexxProxy(), error 1: argument 1 must be RexxProxy object, received '<O>org.rexxla.bsf.eng ines.rexx.RexxProxy@c40c80' of type 'The String class'.] org.rexxla.bsf.engines.rexx.RexxException: BSF4Rexx/routine/jniRexxRunProgram(), error 8: 13 *-* testUnit=BsfRexxProxy(rpTestUnit, "ooRexxObject") -- get ooRexx object that gets proxied Error 40 running rexx line 13: Incorrect call to routine Error 40.900: BSF4Rexx/routine/BsfRexxProxy(), error 1: argument 1 must be RexxProxy object, received '<O>org.rexxla.bsf.eng ines.rexx.RexxProxy@c40c80' of type 'The String class'. at org.rexxla.bsf.engines.rexx.RexxAndJava.jniRexxRunProgram(Native Method) at org.rexxla.bsf.engines.rexx.RexxEngine.apply(RexxEngine.java:812) at rgf.F_multiThreading.TestNestedEngines_80$ThreadedJNIRexxStart80.run(TestNestedEngines_80.java:140) at java.lang.Thread.run(Thread.java:619) JAVA - TestNestedEngines_80.java: returned from all Java threads! nrJavaThreads=23 --- On another run the script bombs while Java has control, yielding the following log-data: # # An unexpected error has been detected by Java Runtime Environment: # # EXCEPTION_ACCESS_VIOLATION (0xc0000005) at pc=0x0044866a, pid=6428, tid=5076 # # Java VM: Java HotSpot(TM) Client VM (11.0-b16 mixed mode, sharing windows-x86) # Problematic frame: # C [rexx.dll+0x1866a] # # If you would like to submit a bug report, please visit: # http://java.sun.com/webapps/bugreport/crash.jsp # The crash happened outside the Java Virtual Machine in native code. # See problematic frame for where to report the bug. # --------------- T H R E A D --------------- Current thread (0x00fdac00): JavaThread "Thread-7" [_thread_in_native, id=5076, stack(0x038f0000,0x03970000)] siginfo: ExceptionCode=0xc0000005, reading address 0x00000012 Registers: EAX=0x00000000, EBX=0x26b229b0, ECX=0x00000000, EDX=0x00000002 ESP=0x0396eb70, EBP=0x0396eb74, ESI=0x26b229b0, EDI=0x00fdac00 EIP=0x0044866a, EFLAGS=0x00010216 Top of Stack: (sp=0x0396eb70) 0x0396eb70: 00000000 0396eb80 0045c962 7f2577a8 0x0396eb80: 0396eb90 0045de41 7f2577a8 7efd13e0 0x0396eb90: 0396eba4 004453f6 00000002 00000002 0x0396eba0: 7f2577a8 0396ebb8 0044a786 7f384348 0x0396ebb0: 7f1a77d8 00000000 0396ebec 00484159 0x0396ebc0: 7f384348 7f2577a8 25529426 7f384348 0x0396ebd0: 7f0e6f50 7f384348 7f384348 7f384348 0x0396ebe0: 0396ec20 0050f120 ffffffff 0396ec2c Instructions: (pc=0x0044866a) 0x0044865a: cc cc cc cc cc cc 55 8b ec 51 89 4d fc 8b 45 fc 0x0044866a: 0f b7 40 12 83 e0 01 f7 d8 1b c0 83 c0 01 8b e5 Stack: [0x038f0000,0x03970000], sp=0x0396eb70, free space=506k Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code) C [rexx.dll+0x1866a] C [rexx.dll+0x2c962] C [rexx.dll+0x2de41] C [rexx.dll+0x153f6] C [rexx.dll+0x1a786] C [rexx.dll+0x54159] C [rexx.dll+0x542d1] C [rexx.dll+0x8b5cb] C [rexx.dll+0x46d40] C [rexx.dll+0x932ca] C [rexx.dll+0x84b08] C [rexx.dll+0x497f2] C [rexx.dll+0x497c6] C [rexx.dll+0x434ea] C [rexx.dll+0x59b97] C [rexx.dll+0x59b3a] C [rexx.dll+0x1cf59] C [rexx.dll+0x52b38] C [rexx.dll+0x5d5b6] C [rexx.dll+0x4e063] C [rexx.dll+0x698e6] C [BSF4Rexx.dll+0x823e] C [BSF4Rexx.dll+0x425a] j org.rexxla.bsf.engines.rexx.RexxAndJava.jniRexxRunProgram(Ljava/lang/String;ILjava/lang/String;Ljava/lang/String;[Ljava/lang/Object;)Ljava/lang/Object;+0 j org.rexxla.bsf.engines.rexx.RexxEngine.apply(Ljava/lang/String;IILjava/lang/Object;Ljava/util/Vector;Ljava/util/Vector;)Ljava/lang/Object;+468 j rgf.F_multiThreading.TestNestedEngines_80$ThreadedJNIRexxStart80.run()V+202 j java.lang.Thread.run()V+11 v ~StubRoutines::call_stub Java frames: (J=compiled Java code, j=interpreted, Vv=VM code) j org.rexxla.bsf.engines.rexx.RexxAndJava.jniRexxRunProgram(Ljava/lang/String;ILjava/lang/String;Ljava/lang/String;[Ljava/lang/Object;)Ljava/lang/Object;+0 j org.rexxla.bsf.engines.rexx.RexxEngine.apply(Ljava/lang/String;IILjava/lang/Object;Ljava/util/Vector;Ljava/util/Vector;)Ljava/lang/Object;+468 j rgf.F_multiThreading.TestNestedEngines_80$ThreadedJNIRexxStart80.run()V+202 j java.lang.Thread.run()V+11 v ~StubRoutines::call_stub --------------- P R O C E S S --------------- Java Threads: ( => current thread ) 0x03400000 JavaThread "Thread-23" [_thread_in_native, id=4840, stack(0x040f0000,0x04170000)] 0x033fe000 JavaThread "Thread-22" [_thread_in_native, id=4572, stack(0x04070000,0x040f0000)] 0x033fcc00 JavaThread "Thread-21" [_thread_in_native, id=6368, stack(0x03ff0000,0x04070000)] 0x033f9800 JavaThread "Thread-20" [_thread_in_native, id=6288, stack(0x03f70000,0x03ff0000)] 0x033f8000 JavaThread "Thread-19" [_thread_in_native, id=6424, stack(0x03ef0000,0x03f70000)] 0x033f6c00 JavaThread "Thread-18" [_thread_in_native, id=5892, stack(0x03e70000,0x03ef0000)] 0x033f5400 JavaThread "Thread-17" [_thread_in_native, id=3168, stack(0x03df0000,0x03e70000)] 0x00fd3000 JavaThread "Thread-16" [_thread_in_native, id=5920, stack(0x03d70000,0x03df0000)] 0x00fd1800 JavaThread "Thread-15" [_thread_in_native, id=1064, stack(0x03cf0000,0x03d70000)] 0x00fd0800 JavaThread "Thread-14" [_thread_in_native, id=7972, stack(0x03c70000,0x03cf0000)] 0x00fcdc00 JavaThread "Thread-13" [_thread_in_native, id=4832, stack(0x03bf0000,0x03c70000)] 0x00fcc800 JavaThread "Thread-12" [_thread_in_native, id=5140, stack(0x03b70000,0x03bf0000)] 0x00fcb400 JavaThread "Thread-11" [_thread_in_native, id=6768, stack(0x03af0000,0x03b70000)] 0x00fdec00 JavaThread "Thread-10" [_thread_in_native, id=8088, stack(0x03a70000,0x03af0000)] 0x00fdd800 JavaThread "Thread-9" [_thread_in_native, id=4996, stack(0x039f0000,0x03a70000)] 0x00fdc000 JavaThread "Thread-8" [_thread_in_native, id=6904, stack(0x03970000,0x039f0000)] =>0x00fdac00 JavaThread "Thread-7" [_thread_in_native, id=5076, stack(0x038f0000,0x03970000)] 0x033f4800 JavaThread "Thread-6" [_thread_in_native, id=7212, stack(0x03870000,0x038f0000)] 0x033f3400 JavaThread "Thread-5" [_thread_in_native, id=496, stack(0x037f0000,0x03870000)] 0x033f1c00 JavaThread "Thread-4" [_thread_in_native, id=5876, stack(0x03770000,0x037f0000)] 0x0344c400 JavaThread "Thread-3" [_thread_in_native, id=4580, stack(0x036f0000,0x03770000)] 0x0344b000 JavaThread "Thread-2" [_thread_in_native, id=6324, stack(0x03670000,0x036f0000)] 0x033f0400 JavaThread "Thread-1" [_thread_in_native, id=1428, stack(0x035f0000,0x03670000)] 0x00f12000 JavaThread "Low Memory Detector" daemon [_thread_blocked, id=6616, stack(0x032f0000,0x03370000)] 0x00f0f000 JavaThread "CompilerThread0" daemon [_thread_blocked, id=4164, stack(0x03270000,0x032f0000)] 0x00f0a400 JavaThread "Attach Listener" daemon [_thread_blocked, id=2720, stack(0x031f0000,0x03270000)] 0x00f09000 JavaThread "Signal Dispatcher" daemon [_thread_blocked, id=7460, stack(0x01160000,0x011e0000)] 0x00f00c00 JavaThread "Finalizer" daemon [_thread_blocked, id=7472, stack(0x010e0000,0x01160000)] 0x00eff800 JavaThread "Reference Handler" daemon [_thread_blocked, id=5868, stack(0x01060000,0x010e0000)] 0x00d67000 JavaThread "main" [_thread_blocked, id=5052, stack(0x00030000,0x000b0000)] Other Threads: 0x00efdc00 VMThread [stack: 0x00fe0000,0x01060000] [id=5896] 0x00f13800 WatcherThread [stack: 0x03370000,0x033f0000] [id=7340] VM state:not at safepoint (normal execution) ... cut ... ---------------------------------------------------------------------- Comment By: Rick McGuire (bigrixx) Date: 2009-09-23 16:05 Message: This fix will only work with other changes previously made to the trunk version. This problem goes away with trunk, which is the only version we're supporting at the moment, unless we decide to ship some point release. ---------------------------------------------------------------------- Comment By: Rony G. Flatscher (orexx) Date: 2009-09-23 14:45 Message: Applied the fix to the release version of ooRexx and ran the tests. Still, there are exceptions using the stress tests --------------------------- this occurs at the end of the program: > rexx.dll!RexxLocalVariables::get(unsigned int index=3) Line 119 + 0x10 bytes C++ rexx.dll!RexxActivation::getLocalVariable(RexxString * name=0x7fcb06d8, unsigned int index=3) Line 457 + 0x12 bytes C++ rexx.dll!RexxActivation::setLocalVariable(RexxString * name=0x7fcb06d8, unsigned int index=3, RexxObject * value=0x7fd4af70) Line 513 + 0x10 bytes C++ rexx.dll!RexxInstructionMessage::execute(RexxActivation * context=0x7ef61918, RexxExpressionStack * stack=0x7ef619d8) Line 246 C++ rexx.dll!RexxActivation::run(RexxObject * _receiver=0x7eff88d0, RexxString * msgname=0x7f21b358, RexxObject * * _arglist=0x7e2ba0ac, unsigned int _argcount=7, RexxInstruction * start=0x00000000, ProtectedObject & resultObj={...}) Line 516 C++ rexx.dll!RexxActivation::dispatch() Line 375 + 0x33 bytes C++ rexx.dll!RexxActivity::runThread() Line 123 C++ rexx.dll!call_thread_function(void * arguments=0x7f101778) Line 63 C++ kernel32.dll!7c80b729() [Frames below may be incorrect and/or missing, no symbols loaded for kernel32.dll] rexx.dll!SysMutex::release() Line 134 C++ Message: Unhandled exception at 0x00318ca0 (rexx.dll) in rexx.exe: 0xC0000005: Access violation reading location 0x0000000c. --------------------------- another multithreaded stress test would get an exception, but Java would intercept and give information about it. First the console output from running the Rexx program, followed by Java's log file about the exception, indicating an "impossible" argument (the threadname cannot be null, it always has a value): JAVA - before, thread [Thread-12], RIID=[7F4EF1D0] TestNestedEngines: threadName=[null], Throwable=[org.rexxla.bsf.engines.rexx.RexxException: BSF4Rexx/routine/jniRexxRunProgra m(), error 8: 40 *-* ::requires BSF.CLS Error 93 running rexx line 40: Incorrect call to method Error 93.938: Method argument 2 must have a string value] org.rexxla.bsf.engines.rexx.RexxException: BSF4Rexx/routine/jniRexxRunProgram(), error 8: 40 *-* ::requires BSF.CLS Error 93 running rexx line 40: Incorrect call to method Error 93.938: Method argument 2 must have a string value at org.rexxla.bsf.engines.rexx.RexxAndJava.jniRexxRunProgram(Native Method) at org.rexxla.bsf.engines.rexx.RexxEngine.apply(RexxEngine.java:812) at rgf.F_multiThreading.TestNestedEngines_80$ThreadedJNIRexxStart80.run(TestNestedEngines_80.java:140) at java.lang.Thread.run(Thread.java:619) # # An unexpected error has been detected by Java Runtime Environment: # # EXCEPTION_ACCESS_VIOLATION (0xc0000005) at pc=0x002f1722, pid=3512, tid=5984 # # Java VM: Java HotSpot(TM) Client VM (11.0-b16 mixed mode, sharing windows-x86) # Problematic frame: # C [rexx.dll+0x21722] # # An error report file with more information is saved as: # E:\rony\dev\bsf\src\source_cc_40\testUnits\bsf4rexx\rgf\F_multiThreading\hs_err_pid3512.log # -- Excerpt from Java's log-file about the exception: # # An unexpected error has been detected by Java Runtime Environment: # # EXCEPTION_ACCESS_VIOLATION (0xc0000005) at pc=0x002f1722, pid=3512, tid=5984 # # Java VM: Java HotSpot(TM) Client VM (11.0-b16 mixed mode, sharing windows-x86) # Problematic frame: # C [rexx.dll+0x21722] # # If you would like to submit a bug report, please visit: # http://java.sun.com/webapps/bugreport/crash.jsp # The crash happened outside the Java Virtual Machine in native code. # See problematic frame for where to report the bug. # --------------- T H R E A D --------------- Current thread (0x0346e400): JavaThread "Thread-23" [_thread_in_native, id=5984, stack(0x04160000,0x041e0000)] siginfo: ExceptionCode=0xc0000005, reading address 0x00000008 Registers: EAX=0x00000000, EBX=0x26b229b0, ECX=0x7f660650, EDX=0x7f660650 ESP=0x041deb34, EBP=0x041deb44, ESI=0x26b229b0, EDI=0x0346e400 EIP=0x002f1722, EFLAGS=0x00010206 Top of Stack: (sp=0x041deb34) 0x041deb34: 00000012 003da600 00000012 7f660650 0x041deb44: 041deb54 002f1b5b 003da600 003da600 0x041deb54: 041deb60 002f228a 003da600 041deb70 0x041deb64: 002f6e44 003da6ac 0000017d 041deb84 0x041deb74: 002f23bc 00000be8 003da600 00000000 0x041deb84: 041deb9c 002e13de 00000be8 00000022 0x041deb94: 00000022 00000be8 041debb0 0031f10c 0x041deba4: 00000bc4 00000024 041debc0 041debd8 Instructions: (pc=0x002f1722) 0x002f1712: c8 08 00 00 8b 4d f8 51 8b 55 fc 8b 02 8b 4d fc 0x002f1722: 8b 50 08 ff d2 eb 97 8b e5 5d c2 04 00 cc 55 8b Stack: [0x04160000,0x041e0000], sp=0x041deb34, free space=506k Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code) C [rexx.dll+0x21722] C [rexx.dll+0x21b5b] C [rexx.dll+0x2228a] C [rexx.dll+0x26e44] C [rexx.dll+0x223bc] C [rexx.dll+0x113de] C [rexx.dll+0x4f10c] C [rexx.dll+0x1df65] C [rexx.dll+0x1e0d4] C [rexx.dll+0x7e6e7] C [rexx.dll+0x1c503] C [rexx.dll+0x6757f] C [BSF4Rexx.dll+0x8202] C [BSF4Rexx.dll+0x4236] j org.rexxla.bsf.engines.rexx.RexxAndJava.jniRexxRunProgram(Ljava/lang/String;ILjava/lang/String;Ljava/lang/String;[Ljava/lang/Object;)Ljava/lang/Object;+0 j org.rexxla.bsf.engines.rexx.RexxEngine.apply(Ljava/lang/String;IILjava/lang/Object;Ljava/util/Vector;Ljava/util/Vector;)Ljava/lang/Object;+468 j rgf.F_multiThreading.TestNestedEngines_80$ThreadedJNIRexxStart80.run()V+202 j java.lang.Thread.run()V+11 v ~StubRoutines::call_stub Java frames: (J=compiled Java code, j=interpreted, Vv=VM code) j org.rexxla.bsf.engines.rexx.RexxAndJava.jniRexxRunProgram(Ljava/lang/String;ILjava/lang/String;Ljava/lang/String;[Ljava/lang/Object;)Ljava/lang/Object;+0 j org.rexxla.bsf.engines.rexx.RexxEngine.apply(Ljava/lang/String;IILjava/lang/Object;Ljava/util/Vector;Ljava/util/Vector;)Ljava/lang/Object;+468 j rgf.F_multiThreading.TestNestedEngines_80$ThreadedJNIRexxStart80.run()V+202 j java.lang.Thread.run()V+11 v ~StubRoutines::call_stub --------------- P R O C E S S --------------- Java Threads: ( => current thread ) =>0x0346e400 JavaThread "Thread-23" [_thread_in_native, id=5984, stack(0x04160000,0x041e0000)] 0x0346d000 JavaThread "Thread-22" [_thread_in_native, id=5704, stack(0x040e0000,0x04160000)] 0x03469c00 JavaThread "Thread-21" [_thread_in_native, id=6848, stack(0x04060000,0x040e0000)] 0x03468000 JavaThread "Thread-20" [_thread_in_native, id=7644, stack(0x03fe0000,0x04060000)] 0x03466c00 JavaThread "Thread-19" [_thread_in_native, id=668, stack(0x03f60000,0x03fe0000)] 0x03465400 JavaThread "Thread-18" [_thread_in_native, id=4612, stack(0x03ee0000,0x03f60000)] 0x00fdc000 JavaThread "Thread-17" [_thread_in_native, id=4760, stack(0x03e60000,0x03ee0000)] 0x00fda800 JavaThread "Thread-16" [_thread_in_native, id=1404, stack(0x03de0000,0x03e60000)] 0x00fd9400 JavaThread "Thread-15" [_thread_in_native, id=8068, stack(0x03d60000,0x03de0000)] 0x00fd8400 JavaThread "Thread-14" [_thread_in_native, id=3508, stack(0x03ce0000,0x03d60000)] 0x00fcc800 JavaThread "Thread-13" [_thread_in_native, id=2384, stack(0x03c60000,0x03ce0000)] 0x00fcb400 JavaThread "Thread-12" [_thread_in_native, id=6932, stack(0x03be0000,0x03c60000)] 0x00fca400 JavaThread "Thread-11" [_thread_in_native, id=3588, stack(0x03b60000,0x03be0000)] 0x03463800 JavaThread "Thread-10" [_thread_in_native, id=1300, stack(0x03ae0000,0x03b60000)] 0x03462400 JavaThread "Thread-9" [_thread_in_native, id=4768, stack(0x03a60000,0x03ae0000)] 0x03461400 JavaThread "Thread-8" [_thread_in_native, id=8172, stack(0x039e0000,0x03a60000)] 0x034bb800 JavaThread "Thread-7" [_thread_in_native, id=6784, stack(0x03960000,0x039e0000)] 0x034ba000 JavaThread "Thread-6" [_thread_in_native, id=7316, stack(0x038e0000,0x03960000)] 0x00fd6400 JavaThread "Thread-5" [_thread_in_native, id=6576, stack(0x03860000,0x038e0000)] 0x00fd4400 JavaThread "Thread-3" [_thread_in_native, id=7172, stack(0x03760000,0x037e0000)] 0x00fde800 JavaThread "Thread-2" [_thread_in_native, id=5816, stack(0x036e0000,0x03760000)] 0x00fd1000 JavaThread "Thread-1" [_thread_in_native, id=7872, stack(0x03660000,0x036e0000)] 0x00f12000 JavaThread "Low Memory Detector" daemon [_thread_blocked, id=6156, stack(0x03360000,0x033e0000)] 0x00f0bc00 JavaThread "CompilerThread0" daemon [_thread_blocked, id=4016, stack(0x032e0000,0x03360000)] 0x00f0a400 JavaThread "Attach Listener" daemon [_thread_blocked, id=7724, stack(0x03260000,0x032e0000)] 0x00f09000 JavaThread "Signal Dispatcher" daemon [_thread_blocked, id=7256, stack(0x031e0000,0x03260000)] 0x00f00c00 JavaThread "Finalizer" daemon [_thread_blocked, id=1332, stack(0x010e0000,0x01160000)] 0x00eff800 JavaThread "Reference Handler" daemon [_thread_blocked, id=6184, stack(0x01060000,0x010e0000)] 0x00d67000 JavaThread "main" [_thread_blocked, id=6492, stack(0x00030000,0x000b0000)] Other Threads: 0x00efdc00 VMThread [stack: 0x00fe0000,0x01060000] [id=6968] 0x00f14000 WatcherThread [stack: 0x033e0000,0x03460000] [id=6092] VM state:not at safepoint (normal execution) ---------------------------------------------------------------------- Comment By: Rick McGuire (bigrixx) Date: 2009-09-23 05:46 Message: Committed revision 5204. ---------------------------------------------------------------------- Comment By: Rony G. Flatscher (orexx) Date: 2009-09-23 02:32 Message: That's really good news for me, thank you very much Jean-Louis! I have become quite unsecure with this problem, as initially I did not understand the cause, then thought it was with either Java (JNI) or BSF4Rexx, to finally get just a "feeling" from more than six (!) weeks of intensive debugging attempts, that the cause may be in ooRexx (after e.g. securing BSF4Rexx for buffer overruns and other "littler" things until I ran out of possible causes and candidates). Due to the "nature of the biest" it was not easy to come up with an example that would rule out Java and BSF4Rexx, such that becomes possible for others to get the crash with pure ooRexx. So I am truly happy that this seems to have been achieved, as you can reproduce it, which is great as now it may become possible to analyze it in the ooRexx kernel! Not sure whether I should speculate (short of any hard facts and reproducable cases) what may happen at times. But looking back at tons and tons of debug outputs through August and September, it appears to be the case that sometimes either function calls pass the wrong argument or fetch a wrong return value. ---------------------------------------------------------------------- Comment By: jfaucher (jfaucher) Date: 2009-09-23 00:43 Message: Hi Rony, Just to tell I can reproduce the crash. If not closed, I will investigate more next WE. Jean-Louis ---------------------------------------------------------------------- You can respond by visiting: https://sourceforge.net/tracker/?func=detail&atid=684730&aid=2863643&group_id=119701 |