Multithreaded tracing, TraceObject class ---------------------------------------- This readme.txt file accompanies a portable Windows version of ooRexx 5.1beta that implements multithreaded trace prefixes and makes it possible to create one own's trace line renderings as well as to use the infrastructure for profiling (analyzing) the execution of Rexx programs. - unzip the ooRexx portable version, go into the directory and run "setupoorexx.cmd" which creates batch files, e.g.: - setenv2rxenv.cmd ... run to change PATH to first point to the portable version of ooRexx; run Rexx programs with "rexx myProgram.rex" such that the operating system looks and finds for rexx.exe - the following files can be found in test_scripts.zip - there are a few test Rexx programs (you can use your own Rexx programs): - test01.rex ... a simple test Rexx program - test02.rex ... a multithreaded test Rexx program to test guarded and unguarded method routines - test03.rex ... this is test01.rex with an intenional syntax error at the end - docpgm.rex ... a program using many threads, can be used to determine the formatting option and the number of objects to create, usage: rexx docpgm [option [nrObjects]] where option is one of 'N', 'T', 'S', 'F', 'P' nrObjects is a number>0 - traceutil.cls ... WIP: a little set of utilities for .TraceObject, e.g. the routines toJsonFile(collection[, Minimal|Crlf|Human]) and toCsvFile(collection[,createTitle?]), fromJsonFile(filename), fromCsvFile(filename), comparators for sorting collections of traceObjects in different manners (.sortByThreadInvocationNr, .sortByInvocationNr, .sortByAttributePoolNr) - there are three Rexx programs that exploit the new infrastructure: - p1_traceRunner.rex ... executes the Rexx program (name supplied via the command line argument) four times, once with .TraceObject~option set to 'N' (normal), 'T' (thread), 'S' (standard), 'F' (full), 'P' (profiling mode); each run will have the generated TraceObjects collected in an array that could be used to analyze the runs afterwards - p2_traceInterceptor.rex ... like p1_traceRunner.rex in addition: demonstrates how to intercept each TraceObject - p3_makestring_method.rex ... demonstrates defining a makeString method (from a floating method or a resource) to replace the TraceObject's default implementation; Mike suggested to include the thread number in the (originally three character) trace prefix, which "::method myMakeString03" demonstrates, here the suggestion: - p4_traceEditingPrefix.rex ... like p2_traceInterceptor.rex in addition: - demonstrates how to change the trace line information - demonstrates sorting the TraceObjects in different ways using comparators (sortByThreadInvocationNr, sortByInvocationNr) and using the default sort order (by NR) - demonstrates how to fetch the total TraceObjects created so far - p5_create_tracefiles.rex ... runs the supplied Rexx program and creates three JSON files (minimal, crlf, human legible) and two CSV files (with header and without header) - p6_recreate_from_tracefiles.rex ... recreates the traceObject collection from the supplied JSON or CSV file - p7_annotate_effective_state.rex ... WIP: runs the supplied Rexx program and then annotates the traceObjects with isRunning and hasGuardState entries To use the infrastructure: - unzip the portable ooRexx version, run setupoorexx.cmd, then the generated script setenv2rxenv.cmd and remain in that session to run the above programs (PATH got set in it), e.g. rexx p1_traceRunner.rex test01.rex (or any other Rexx program) rexx p2_traceInterceptor.rex test02.rex (or any other Rexx program) rexx p3_traceEditingPrefix.rex test03.rex (or any other Rexx program) ... rexx docpgm.rex n 2 ... option=normal rounds=2 (two objects) rexx docpgm.rex t 2 ... option=thread rounds=2 (two objects) rexx docpgm.rex s 2 ... option=standard rounds=2 (two objects) rexx docpgm.rex f 2 ... option=full rounds=2 (two objects) Please note: the test programs are artificial and got created to test and demonstrate the infrastructure. --- What follows are drafts for rexxref.pdf. --------------------------------------------------------------------- Starting out with the current documentation the nomenclature is kept the same, possibly with additional information meant for the debugging section in rexxref.pdf. --- draft (rexxref.pdf) - begin --- 15.4 Debugging Multithreaded Programs ooRexx allows for executing different parts of ooRexx programs on multiple threads of execution using different Rexx interpreter within a single operating system process. This makes it difficult and at times even impossible to debug such multithreaded programs without any additional information about the specific execution context. Relevant information for debugging multithreaded programs may be: the Rexx interpreter instance that executes an invocation ("activation") running on which operating system thread and whether a lock is held for exclusive access of an object's attribute ("object variable") pool. To ease debugging of multithreaded programs the execution context can be indicated with a "multithreaded trace prefix" ("OPTION") string in the following form "[R1 T2 I3 G A4 L5 *]", where - "R1": "R" stands for Rexx interpreter instance and the number (a counter) indicates which of the instances executes the current invocation (activation). - "T2": "T" stands for (operating system) thread and the number (a counter) indicates on which of the currently existing threads the activity gets executed - "I3": "I" stands for invocation (activation) and the number (a counter) indicates which invocation gets executed on that thread (activity) Information in the OPTION if currently tracing statements of method routines (otherwise the remainder of the prefix will be blank): - "G" or "U": this character indicates whether the method routine is defined to be guarded or unguarded. - "A4" : "A" stands for "attribute pool" ("object variable dictionary") and the number (a counter) indicates which object variable dictionary gets used in this invocation of the method routine. Each object will have its own attribute pool which can be directly accessed by method routines of the same scope, i.e. method routines that are defined in the same class from which the object got created. Therefore the A indicator will refer to the same object if the number is the same. - "L5": "L" stands for object lock count and the number (a counter) indicates how many object lock reservations have taken place at that point in time. Whenever another method routine of the same scope gets invoked the object lock count increases by one, upon return the object lock count decreases by one. - "*" or " ": the asterisk indicates that the activity holds the object lock. Guarded methods are blocked, if they do not hold the object lock. Methods in the unguarded state will never block. Notes: - The GUARD keyword instruction can be used within a method routine to change the state from guarded (synchronize on the object lock) to unguarded (ignore the object lock) using unconditionally the keyword statement GUARD OFF and vice versa (using unconditionally the keyword statement GUARD ON). - The keyword instructions "GUARD ON someAttribute=someValue" and "GUARD OFF someAttribute=someValue" allow changing the state of the method routine to guarded or to unguarded depending on the value of an exposed attribute "someAttribute" which needs to get changed in another concurrently running method routine of the same (class) scope. Such attributes are known to be used as "control variables" to synchronize activities on different threads. - If you wish to directly change the value of any exposed attribute then make sure that the changes take place in the guarded state to inhibit concurrent updates from other threads to inhibit inconsistent states. - The object variable dictionary number represents a specific object. - Methods in the guarded state that do not possess the trailing asterisk are blocked, they are waiting for the object lock. - Methods in the unguarded state get never blocked. - The standard layout of the OPTION is intentionally designed to make parsing easy such that analyzing the trace output of complex multithreaded ooRexx programs becomes easy. Starting with ooRexx 5.1, each traced line will be represented with an instance of the class TraceObject. Its class attribute OPTION (see the documentation of the class TraceObject) is set to N (normal) by default. If one needs additional, multithreaded trace information prefixed then changing the class attribute OPTION to S (standard) or to F (full, for complex multithreaded programs) prepends it to each traced line. Each TraceObject will be sent as argument to the LINEOUT message to the .traceOutput monitor object. This makes it possible to intercept these trace LINEOUT messages with the TraceObject argument by adding one own's Rexx object as a destination object which implements the LINEOUT method (if doing so, one should also implement the UNKNOWN method to forward all unknown messages). --- draft (rexxref.pdf) - end --- --- draft for class TraceObject (rexxref.pdf) - begin --- 5.3.x TraceObject Class A TraceObject is a subclass of StringTable and therefore is a MapCollection using unique character string indexes. The items of a StringTable can be any valid Rexx object. See also the Directory Class, a MapCollection similar to StringTable, but with additional methods setMethod and unsetMethod. The trace infrastructure of ooRexx will create an instance for each trace line and store the following information with the following indexes: Index Item "ATTRIBUTEPOOL" a number, makeString prepends it with the letter A "HASOBJECTLOCK" .true/.false, makeString uses an asterisk, if .true, a blank character else "INTERPRETER" a number, makeString prepends it with the letter R "INVOCATION" a number, makeString prepends it with the letter I "ISGUARDED" .true/.false, makeString uses the letter G, if .true, the letter U else "NR" indicates the sequential creation position (used for the default sorting) "OBJECTLOCKCOUNT" a number, makeString prepends it with the letter L "OPTION" the option at creation time, e.g. N or S "THREAD" a number, makeString prepends it with the letter T "TIMESTAMP" the creation .DateTime "TRACELINE" the trace line string The section "15.4 Debugging Multithreaded Programs" gives more information about debugging multithreaded programs. r.3.x.1. collector (Class Attribute) This attribute controls whether created TraceObjects get collected or not. If its value is set to .nil (default) then the created TraceObjects are not collected. This attribute can be set to anything else, if the object can understand the APPEND message, which is the case for all OrderedCollections like Array. r.3.x.1. counter (Class Getter Attribute) This attribute gets used to number the TraceObjects. Its value represents the total number of TraceObjects created so far. r.3.x.2. option (Class Attribute) This attribute controls whether a traced line gets displayed and how makeString renders the traced line. The following values are defined for this attribute: Letter N "normal", the trace line gets displayed without any multithreaded prefix information. T "thread", the trace prefix gets the thread number inserted after the second character in it S "standard", the trace line gets prefixed with a bracketed string that indicates the thread and the invocation number, e.g. "[T1 I2 ]" or if a method routine gets traced in addition whether it was defined guarded or unguarded, the object lock count and whether the object lock is reserved (indicated by an asterisk), e.g. "[T1 I2 G L3 *] ". F "full", the trace line with a bracketed string that adds the Rexx instance and the activity pool number, e.g. "[R1 T2 I3 ]" or if a method routine gets traced adds the attribute pool number, e.g. "R1 T2 I3 G A4 L5 *]". P "profiling", no trace line will be shown, yet, each created TraceObject will get appended to the class attribute COLLECTOR if not .nil. This allows analyzing the execution of traced Rexx programs for many purposes. r.3.x.3. makeStringImpl (Class Method) This method implements the traceline formatting according to the current setting of the class attribute OPTION: N or P normal trace line T thread will be inserted into trace prefix S standard prefix prepended to trace line F full prefix prepended to trace line This method requires a single TraceObject as its argument and returns a string representing the traceline. Using setMakeString one is able to replace this method with a customized method. For more information see class attribute OPTION and section "15.4 Debugging Multithreaded Programs". r.3.x.4. setMakeString (Class Method) This method allows the Rexx programmer to supply a customized makeStringImpl method that will be used to replace makeStringImpl. The supplied method receives a single TraceObject as an argument and must return a string. r.3.x.5. unsetMakeString (Class Method) Cancels the effect of all previous setMakeString invocations. r.3.x.6. compareTo Implements the default sort order using the value of the NR entry which is the creation sequence number. r.3.x.7. makeString This method will invoke the class method makeStringImpl supplying the TraceObject pointed to by the self variable as argument. --- draft for class TraceObject (rexxref.pdf) - end --- If there are questions, comments please use the ooRexx developer list on sourceforge (https://sourceforge.net/p/oorexx/mailman/oorexx-devel/). Temporary location: 2024-02-05, rgf