[BTRACE-37] Rolling File Output when scriptOutputFile is specified

[jbachorik]

[reporter="joachimhskeie", created="Sun, 14 Mar 2010 23:30:40 +0100", resolved="Sat, 24 Apr 2010 19:48:49 +0200"]

When the parameter scriptOutputFile is specified all BTrace output is appended to a single file. It would be nice if this file could be rolled (either time based or triggered with a BTrace Script - or both) and its number incremented. This is both to be able to set up output file deletion (so to not overflow the filesystem with script output, as well as enabling integration with the BTrace agent to a remote application.

As a developer of EurekaJ, I need a consistent feature that will allow integration with the EurekaJ Mangager where BTrace Script output is passed along to the manager application via HTTP, JMS og Webservice calls. (A conceptual drawing of the intended architecture is found at: http://confluence.haagen.name/display/eurekaj/Overall%20Arcitecture).

This issue originated from BTRACE-29 which wont be included in the BTrace source.

This issue can be implemented with something like:

File scriptOutputFile_renameFrom = new File(scriptOutputFile);
File scriptOutputFile_renameTo = new File(scriptOutputFile + ".1");
if (scriptOutputFile_renameFrom.exists()) {

if (scriptOutputFile_renameTo.exists()) {

scriptOutputFile_renameTo.delete();

}

scriptOutputFile_renameFrom.renameTo(scriptOutputFile_renameTo);

}

}

[jbachorik]

[author="joachimhskeie", created="Sun, 11 Apr 2010 21:11:33 +0200"]

I implemented this feature by adding an agent parameter called "fileRollMilliseconds" that is used to roll the output file. The files are rolled and named with the same name as the argument "scriptOutputFile" with a .NUMBER suffix ranging from 1 to 100. After .100 the .1 file will be overwritten.

Most of the changes are within the FileClient.java class.

Please let me know if something like this will be possible to add to the BTrace source, as it is one of the few integration options left for integration with EurekaJ (Which have now been approved by the Codehaus foundation).

I am attching two diff files, one for Main.java and one for FileClient.java.

[jbachorik]

[author="jbachorik", created="Fri, 23 Apr 2010 16:54:21 +0200"]

I've taken the liberty to modify the patch a bit. I didn't like the changes in FileClient part so I've introduced a kind of strategy class for trace output.
Attaching the patch - if there would be no objections I will integrate early next week.

[jbachorik]

[author="jbachorik", created="Fri, 23 Apr 2010 16:54:42 +0200"]

The modified patch

[jbachorik]

[author="joachimhskeie", created="Fri, 23 Apr 2010 23:58:53 +0200"]

At first overview the patch looks good. I will try to have a closer look at the patch over the weekend.

[jbachorik]

[author="joachimhskeie", created="Sat, 24 Apr 2010 00:20:34 +0200"]

Trying the patch out on the latest version from HG nothing seems to be printed out to the output files for some reason. using stdout=true prints everything out as expected. Setting stdout=false,fileRollMilliseconds=5000 will print out 3 messages to one .btrace file, but after that output is halted.

[jbachorik]

[author="joachimhskeie", created="Sat, 24 Apr 2010 11:14:15 +0200"]

Hello,

I found two bugs in testing this out today. First, if there was multiple btrace.class files specified with scriptdir=/path/to/dir, only one file would be appended to. I fixed this by introducing a local variable in the Main class (otherwise the static variable scriptOutputDir would always be used for each BTrace.class file in scriptdir.

Also, when rolling the outputfiles there was a deadlock situation. I think the deadlock was caused by a writerLock.readLock().lock(); being obtained inside flush. inside nextWriter() a writeLock would be obtained. This caused the writeLock to Deadlock against the readLock.

I am attaching a diff file that creates a diff between btrace-rolling-out.patch and my changes in BTrace.

Another aproach would be to move the unlock and lock in flush to the nextWriter, but in my mind nextWriter shouldnt need to unlock any other locks made elsewhere in the system.

I hope you find this patch useful, and perhaps applicable to Btrace 1.2 ?

[jbachorik]

[author="jbachorik", created="Sat, 24 Apr 2010 19:34:37 +0200"]

Hi Joachim,
thanks for testing. Seems that I got burned by the inability of a ReentrantReadWriteLock to promote read lock to write lock when requested in a thread holding the read lock. Anyway, the only part that needs guarding by the readlock is the one invoking the flush operation on the current file writer. The rest of the method:

 if (needsRoll()) {
  nextWriter();
} 

can be safely placed outside of the read lock.

As for introducing currentBtraceScriptOutput - sounds good and fixes the problem of all probes' output going to the same file if no script output file given. I'm making only small adjustment in the variable initialization so it defaults to the value of scriptOutputFile if provided:

String currentBtraceScriptOutput = scriptOutputFile;
if (currentBtraceScriptOutput == null || currentBtraceScriptOutput.length() == 0) {
   currentBtraceScriptOutput = filename + ".btrace";
   if (isDebug()) debugPrint("scriptOutputFile not specified. defaulting to " + currentBtraceScriptOutput);
}

[jbachorik]

[author="jbachorik", created="Sat, 24 Apr 2010 19:48:49 +0200"]

integrated in http://kenai.com/projects/btrace/sources/hg/revision/296

[jbachorik]

[author="joachimhskeie", created="Sat, 24 Apr 2010 22:52:00 +0200"]

On closer look, I would still like one small change in the getNextWriter() method.

As it currently stands it will start output to a .btrace file. One it rolls it will stop that output and start to output to a .btrace.1 file. On next roll it will stop writing to that file and start writing to a .btrace.2 file, and so on.

The problem with this approach is that I have no way to tell if BTrace have finished writing to the btrace.X file, unless I do a full scan of the directory for a .btrace.X-1 file as well.

I have made some small changes to the nextWriter method so that it works like this:

• Printing is ALWAYS to the .btrace file
• On roll the .btrace file is renamed to .btrace.X and a new .btrace file is created

This way I can easily scan the script directory for any *.btrace.X files, knowing that if I find any of those I can safely read its contents and delete the file. (I am parsing the output and passing the contents along to a remote application via WebServices - once done I have no more use for the physical file).

Unable to attach a diff file as the issue is closed in JIRA, but its contents are:

diff -r f560dd382067 src/share/classes/com/sun/btrace/agent/TraceOutputWriter.java
--- a/src/share/classes/com/sun/btrace/agent/TraceOutputWriter.java Sat Apr 24 22:48:09 2010 +0200
+++ b/src/share/classes/com/sun/btrace/agent/TraceOutputWriter.java Sat Apr 24 22:48:54 2010 +0200
@@ -91,13 +91,14 @@
 }
@Override

-final public void flush() throws IOException {

try {

+final public void flush() throws IOException {


try {

writerLock.readLock().lock();

currentFileWriter.flush();

} finally {

writerLock.readLock().unlock();

}
if (needsRoll()) {

nextWriter();

}

@@ -125,14 +126,19 @@

}

private FileWriter getNextWriter() throws IOException {

File f = new File(path + File.separator + baseName + "." + (counter++));
if (f.exists()) {

-f.delete();


currentFileWriter.close();
File scriptOutputFile_renameFrom = new File(path + File.separator + baseName);
File scriptOutputFile_renameTo = new File(path + File.separator + baseName + "." + (counter++));

if (scriptOutputFile_renameTo.exists()) {

  scriptOutputFile_renameTo.delete();

}
scriptOutputFile_renameFrom.renameTo(scriptOutputFile_renameTo);
scriptOutputFile_renameFrom = new File(path + File.separator + baseName);

if (counter > maxRolls) {

counter = 1;

}


return new FileWriter(f);


return new FileWriter(scriptOutputFile_renameFrom);

}

abstract protected boolean needsRoll();

[jbachorik]

[author="jbachorik", created="Sun, 25 Apr 2010 20:21:28 +0200"]

The patch is ok. Go ahead and push it.

[jbachorik]

[author="jbachorik", created="Sun, 25 Apr 2010 20:25:45 +0200"]

Regarding my last comment - Joachim, I've changed your membership to "developer" so you should be able to push your changes.

[jbachorik]

[author="joachimhskeie", created="Sun, 25 Apr 2010 22:12:56 +0200"]

Pushing changes to Revision 298 .