Filippe and I continued this discussion in email but really should have done so on the fourm. Here are the relevant parts of the exchange.

About the traceln calls: traceln("dbg", "DBG: " + message). I think better change the DBG to DEBUG, VRB to VERBOSE and
NZY to NOIZY, some user can not understand the log messages started with DBG, VRB, NZY. 

Ok, sure we will use those prefixes -- except if you are going to spell these words out the the correct spelling is NOISY not NOIZY.  

When enable the verbose the trace should be enabled also? 

Enabling debug does /not/ enable verbose trace. Debug trace is for end-users and not for generate Byteman-internal trace. Setting
org.jboss.byteman.debug switches on output from /public/ method Helper.debug(). That method is a public instance method because
public instance methods of Helper can be used for built-in calls in Byteman rules.  The new methods that I suggested we use to
implement internal trace, Helper.verbose() and Helper.noisy(), ought to be public static methods. Making them static means that they
are not candidates for use as builtin calls. That's ok because they are nto really intended to be used from rules (that's what debug is
for). That also means we can call them from anywhewre in the Byteman code base without having to create a Helper instance.  I just
realised (doh!) that this means we cannot have these methods simply call trace or traceln since they are both instance methods. These
methods don't actually need to be instance methods since they don't refer to Helper fields. However, they need to be public instance
methods because they are meant to be available as builtins.  So, what we need to do is to redefine trace and traceln so that they cal
 internal static methods Helper.dotrace and Helper.dotraceln and move the code in trace into dotrace and the code in traceln into
dotraceln. All the other methods which use trace streams end up calling trace and traceln so this is the only change we need.  

? Another point is, for each isVerbose() a new PrintWriter is instantiated, it is by design or we can create only one per class where
it is used or change all of the to them to the traceln method? 

Hmm, that's happening here because the print method needs to print a message and a stack trace. We can avoid that by providing a way
of dumping a stacktrace in either verbose or noisy mode.  

Rule.java
...
} catch (TypeWarningException te) {
checkFailed = true;
  if (Transformer.isVerbose()) {
    StringWriter stringWriter = new StringWriter();
    PrintWriter writer = new PrintWriter(stringWriter);
    writer.println("Rule.ensureTypeCheckedCompiled : warning type checking rule " + getName())
    te.printStackTrace(writer);
    detail = stringWriter.toString();
    System.out.println(detail);
  }
  ...

So, what I suggest is that we provide two more methods  verboseStackTrace(Throwable)  and  noisyStackTrace(Throwable)  and then
change code like the example above to this

  . . .
  } catch (TypeWarningException te) {
    checkFailed = true;
    if (Transformer.isVerbose()) {
       Helper.verbose("Rule.ensureTypeCheckedCompiled : warning type checking rule " + getName());
       Helper.verboseStackTrace(te);
    }
  . . .

Methods verboseStackTrace() and noisyStackTrace() will try to lookup a trace with key "vrb" or "nzy". If no trace stream is found they will
default to using System.out. They can both print the exception details by calling Throwable.printStackTrace(PrintStream).  Note that there
is no need for noisyStackTrace() to be passed any bit field values. The stack trace message should always be preceded by a noisy
message which identifies what type of trace is being generated.   

The noisy trace that you suggested is awesome, most of times we want to trace only certain operations, for example to know
if a rule was loaded or not. In this trace when enabled, it will print all varbose|debug logs or only the verbose|debug for the
selected categories? 

My initial idea was that the flag fields should only limit output of noisy trace. So, when you enable org.jboss.byteman.verbose you will
see

    debug|verbose  messages

i.e. you will not see /any/ noisy trace.  When you enable org.jboss.byteman.noisy and select categories by setting

  org.jboss.byteman.noisy.categories="LOAD|INJECT"

you will see messages in groups

  debug|verbose|noisy(INJECT)|noisy(LOAD)

but you won't see messages in groups

  noisy(PARSE)|noisy(TYPE)|noisy(HELPER)|...

If you set org.jboss.byteman.noisy but you leave property org.jboss.byteman.noisy.categories unset or else you set it to a value we
cannot parse correctly then you will see messages in groups

  debug|verbose|noisy(X1)|...|noisy(Xn)

for some set of categories X1, ..., Xn that we need to define.

So, the point of the flags was not to filter the existing verbose messages but to ensure that switching on noisy trace does not swamp
the user with messages for every single thing that Byteman is doing.  Of course, once we have the noisy trace mechanism in place
we can change the level of any of the current verbose messages so that they are generated as noisy messages.  

IF the maks is INVALID and the noisy trace is enabled, it can set the default set and print something like this in the logs:
"THe noisy trace is enabled but no valid category was found, setting the default.". Also, it will be great if the default set of
categories can be edited, makes sense? 

Yes, we will use the default categories if o.j.b.noisy/categories is unset or it contains text which does not identify one of the noisy category
types.

Ok, Filippe, I think the next thing for you to try is  clone the Byteman git repo  implement the new trace model  You don't actually need to modify
all the existing internal tracing calls right away.

Start by adding the static methods Helper.dotrace and Helper.dotraceln and redefine Helper.trace and Helper.traceln to call them.

Next you need to implement Helper.verbose() and Helper.noisy() and also Helper.verboseStackTrace() and Helper.noisyStackTrace().

Once you have done that you can try changing a few places where verbose messages are generated to make sure it correctly writes
trace to System.out.

The next step is to modify class Transformer so that it allows the verbose trace stream to be configured using a System property. This will
allow you to check that verbose output can be redirected to a file.

As a final step, you need to modify class Transformer so that it allows the noisy trace to be enabled and noisy categories to be configured.
It is probably best to use a static long filed in class transformer as a bit mask to record which categories are enabled. You can then provide
a method called Transformer.isNoisy(long) which can be used to test which categories are enabled by checking whether the corresponding
bits in the field are set. That will allow you  to modify some Byteman code so it tests whether to generate a specific type of noisy trace message
and if so calls noisy() to write it. You will also need to allow a tarce stream to be used to write the trace to a file.

After that we will need to convert the existing verbose trace to use Transformer.isVerbose() and Helper.verbose()+Helper.verboseStackTrace().
We will also need to start adding a whole load more verbose and also look at converting some of the other dump code (CFG or bytecode
dumping) so it is controlled by the noisy category configuration. 

Filippe asks:

Hello Andrew, a question, as we will create the dotrace and dotraceln as static we also will need to have the static methods openTrace and traceOpen as well, do you think better we create a new one as static or change it instead add a new?

Oh, nice catch!

traceOpen(Object, String)  is one of the documented builtin methods, part of the Helper convenience API that supports message tracing to stdout/stderr or to files. That means it has to be  a public instance method because Byteman only recognises public instance methods as builtin. That's the only reason why it has to be an instance method though -- the implementation does not actually reference 'this'. So, we can relocate the implementation into a static method and then make the instance method call the static method.

What I suggest is that you redefine traceOpen so it calls a private static method dotraceOpen. Then define dotraceOpen so it does the work currently done by traceOpen. Thsi will allow you to change dotrace(Object,String)  and dotraceln(Object,String) so that they call dotraceOpen instead of openTrace.

Also, just to explain why openTrace exists it's because I was inconsistent in how I named methods in one of the very early releases of Byteman. I moved the code for openTrace into traceOpen, making it part of the trace* builtin family. In order to avoid breaking existing scripts I made openTrace call traceOpen. It probably doesn't need to be kept since I doubt anything important relies on it but it doesn't do any harm to keep it. That explains why trace(Object, String) and traceln(Object, String) both call this method. When I wrote them this was what it was called. But that's also just a matter of legacy. You don't need to change openTrace. It will call its alias traceOpen and that will then call dotraceOpen.

Hi Filippe,

Thanks for the update. It looks ok except for a couple of small details.

The first problem is just a small coding error on your part:

Inside doTrace you have made this change:

-  if (openTrace(identifier)) {
+  if (doTraceOpen(identifier, message)) {

Now, the original call:

openTrace(identifier)

made a call to:

openTrace(identifier, null)

i.e. it passed null as the filename. That means that if there was not already a file associated with identifier then Helper would open a new file using whatever name nextFileName returns.

Your version is calling doTraceOpen(identifier, message) i.e. you are passing the message as the filename. If there is no file name associated with identifier then this will open a new file using the message as the filename. That's not a good idea as the message might be a stack trace! You need to change this line to:

+  if (doTraceOpen(identifier, null)) {

The second problem is a bit more subtle and needs some thinking about. In method closeTrace there are checks to ensure that the streams identified by "out" and "err" cannot be closed. You have extended this to also stop the streams identified by "dbg", "vrb" and "nzy" being closed.

   if (identifier == null ||
+                 identifier.equals("out") ||
-                identifier.equals("err")) {
+                identifier.equals("err") ||
+                // adding new trace levels categories
+                identifier.equals("dbg") ||
+                identifier.equals("vrb") ||
+                identifier.equals("nzy")) {
             return false;

This worked in the original code because "out" and "err" were set up to identify System.out and System.err when class Helper was initialized. If you look at the end of the file you will see

    static {
        traceMap.put("out", System.out);
        traceMap.put("err", System.err);
    }

So, the condition in traceClose ensures that these two streams can never be closed and then re-opened so they point to a file. It also means that we never attempt to close the two PrintStreams identified by "out" and "err" (closing either System.out and System.err would be a very bad thing).

Now, I think we really want "dbg", "vrb" and "nzy" to direct output to System.out as the default destination. However, I think it would also be very useful if the users could redirect output for these trace streams to a file . So, that means we need to manage opening and closing of these streams in a different way.

We only want to use a file for trace streams"dbg", "vrb" and "nzy"  if the user has explicitly called traceOpen  using one of these identifiers and a filename. If not then we want to direct output to System.out. Similarly, we only want to close a trace stream identified by one of these keys if it identifies a file that the user explicitly opened.

So, we can do that as follows:

In doTraceOpen we add an extra check when we find i) there is no existing entry and ii) the filename is null:

        synchronized(traceMap) { 
            PrintStream stream = traceMap.get(identifier);
            String name = fileName;
            if (stream != null) {
                return false;
            }
            if (fileName == null) {
+                if (identifier.equals("dbg") || identifier..equals("vrb") || identifier.equals("nzy")) {
+                    return false;
+                }
                name = nextFileName();
            }

This means that we will only ever insert an entry for these keys into the map when the user has asked for one. So, if the user has opened a stream for these keys then doTrace and doTraceln will find the stream and write to it. If the user has not opened a trace stream then when doTrace and doTraceln fail to find a stream in the map they will call doTraceOpen with null as the filename. The return value false will mean that they use System.out.

That means we don't need to include your change traceClose to deal with trace streams"dbg", "vrb" and "nzy". We get sensible behaviour if we leave it as it is. If the user has opened a trace stream to a file with one of these 3 special names then traceClose will find the file stream, close it and remove it from the map returning true. If the user has no opened a trace stream then traceClose will not find an entry in the map so it will return false.

Could you please go ahead and make these extra changes and then write  some Byteman rules to check that tracing still works ok.

So, first you will need to check that when you call trace("dbg", "some message"), trace("vrb", "some other message") etc  output goes to System.out.

Then you will need to check that when you call traceOpen("dbg", "debug.out"), traceOpen("vrb", verbose.out") etc that the calls to traceln end up adding messages to those files rather than to System.out.

Finally make sure when you call traceClose("dbg"), traceClose("vrb") etc that output reverts back to System.out.

Filippe asked on IRC

another doubt, how exactly we will check for the identifier (vrb and nsy) in the verboseStackTrace and noisyStackTrace methods?

I don't think you need to do anything special here

public static void verboseStackTrace(Throwable th)
{
    doStackTrace("vrb", th);
}

public static void noisyStackTrace(Throwable th)
{
    doStackTrace("nzy", th);
}

private static void doStackTrace(String id, Throwable th)
{
  PrintStream ps;
  synchronized (traceMap) {
    ps = traceMap.get(id);
    if (ps == null) {
      ps = System.out;
    }
  }
  th.printStackTrace(ps);
}

The synchronization is needed to make the get thread safe i.e. it avoids the possibility that another thread might be updating traceMap (under traceOpen or traceClose) when the caller is trying to read it.

Hi Filippe,

Do you have a repo with your updates in that I can review? or maybe even better James could do the review (since he might spot any flaws in my assumptions that got past you :-).

Please write whatever tests you think you need to check this part is working ok and then we can go proceed to the next stage.

regards,

Andrew DInn

Hi Filippe,

Apologies for the delay in returning to this task -- a combination of illness and tight deadlines for OpenJDK work means I was not able to review your fixes until yesterday.

I have now pushed what is for the most part your commit to the main repo. However, I applied a few tweaks to clean things up a bit (here is the commit). The  most obvious difference to the version in your branch is that I regrouped the method definitions into 3 groups, reflecting what I finally realized is the logical organization:

1. the original  Helper builtins (public instance methods) i.e. user API
2. methods for use by the Byteman agent (public static methods) i.e. internal agent API
3. the underlying implementation methods used by both the above (private static methods)

So, when you compare it to your version it will look quite different but that's not really the case. Mostly things have just been moved around.

The above grouping reveals the current structure the code (2 separate APIs over a common implementation) and clarifies the purpose of the methods in each API (static methods provide an internal API for use by the Byteman agent while instance methods provide a user API as Helper builtins). Once I saw this I realized that it made sense to keep doTrace and doTraceln as part of the private implementation and tweak the agent API as follows

  public static boolean out(String message)

  public static boolean err(String message)

  public static boolean verbose(String message)

  public static boolean noisy(String message, int flags)

which delegate to doTraceln(Object identfier, String message)

  public static void outTraceException(Throwable th)

  public static void errTraceException(Throwable th)

  public static void verboseTraceException(Throwable th)

  public static void noisyTraceException(Throwable th, int flags)

which delegate to method

  doTraceException(Object identifier, Throwable th)

n.b. if these names don't look familiar then the implementations should as I just renamed your methods verboseStackTrace, noisyStackTrace and doStackTrace to verboseTraceException, noisyTraceException and doTraceException. This was to make it clear that they print a stack backtrace from an exception argument and are not related to the builtins which print a stack backtrace for the current thread..

The internal agent API methods are almost complete but not quite:

1. Methods out, err, outTraceException and errTraceException print their output unconditionally.
2. Methods verbose and verboseTraceException only print output when Transformer.isVerbose() returns true. So, they are now complete.
3. Methods noisy and noisyTraceException don't currently print anything. In fact the current versions don't even accept an int flags argument

The noisy methods cannot really be completed until we define a set of trace classes and provide some bit field values which can be used i) to supply the flag values indicating which noisy trace classes a message or exception trace belongs to and ii) the set of trace classes enabled by the user. That is one of the two remaining tasks for you to follow up on.

The out, err and verbose methods can be used straight away to replace existing print statements to System.out and System.err in the current agent code. All code that is guarded by if (Transformer.isVerbose()) needs to use the verbose methods. All other printing to System.out or System.err needs to use the out or err methods. That's the other task which is still left for you to do.

n.b. there are two places where I made a change to your code which is worth mentioning (i.e. to add new functionality rather than just rename or reorganize things).

Firstly, I extended the static block of code at the end of class Helper which initializes traceMap. As well as inserting entries for the "out" and "err" streams it now adds entries for dbg", "vrb" and "nzy". These trace streams all initially point to System.out. So, that means that by default debug, verbose and noisy output goes to the tty. Rule code can still redirect the output to a file using the builtins e.g. by calling traceClose("vrb") and then traceOpen("vrb", "myVerboseOutput.log"). That change also required me to add an extra check to traceClose. When it removes a trace stream from traceMap it has to check whether the PrintStream foudn in the map == System.out. In that special case it doesn't close the print stream. Otherwise all other output gets lost!

Secondly, I decided to change the way trace file names are created -- this is only relevant when someone calls traceOpen(X) or traceOpen(X, null) i.e. when they don't supply a name for the output file. In that case a filename is constructed looking a bit like trace0000000000.log, trace0000000001.log etc. The new version still does that for most cases. However, if the trace stream identifier is "dbg", "vrb" or "nzy"  then it uses names like debug0000000001.log, verbose0000000000.log, noisy000000001.log etc.