ojspc slow compilation and tags being recompiled

So we use ojspc (Oracle Java Compiler) to compile our JSPs and tag libraries. This saves us the overhead when loading the sites that it needs to parse the JSPs and Tags and thus slows down the initial first hit on a page.

We used to be able to compile an .ear in about 2 hours (which I think was long already). This project has about roughly 130 JSPs and quite some tag libraries. After a redesign of the site the compilation times started to increase, upto 4 hours, 8 hours, … This was making me nervous as it meant we had to stop our sprints sooner … to test sooner … to start building sooner. This is were my quest for the initial problem began.

Why the hell does ojspc take so long to translate my JSPs??

Roughly .. translating a JSP could take upto 2 minutes, with about 130 JSPs, well that easily takes you 2 hours. I started messing around with ojspc.jar seeing if I could call it natively from code, or if I could override a class and maybe play with the internals of ojspc. Not much success here. After monitoring the ojspc process, I saw it was spawning a javac process every once in a while … probably compiling stuff – right? If only I could have a peak there and see what exactly it was doing … and so I did.

I replaced the standard javac binary with a javac bash script which looked more or less like this:

#!/bin/bash
echo “===============================================================” >> /tmp/compile.log
echo “$$ $PPID : $*” >> /tmp/compile.log

This game me some interesting information on what ojspc was trying to do, however the ojspc process died after trying to translate the first JSP. I assume it wasn’t finding the necessary classes to continue the compilation process.

So playing on with the workaround script – we included the original call the javac binary (now bjavac):

#!/bin/bash
echo “===============================================================” >> /tmp/compile.log
echo “$$ $PPID : $*” >> /tmp/compile.log
jout=`/opt/app/oracle/product/as10g/jdk/bin/bjavac -J-Djavac.pipe.output=true $1 $2 $3 $4 $5 $6 $7 $8 2>>/tmp/compile.log`

This actually compiled the necessary classes from the tag libs, and I noticed several tag libraries were coming back from time to time. For Example we have a <main:header /> tag which includes our common header. This comes back in each JSP. For every JSP this tag library was recompiled. Even worse – if you would have a tag library which formats numbers <main:numberformatter /> and used if several times within the same JSP, it would be recompiled for each occurence of the tag. Since we have custom tag libraries which implements HTML blocks on several parts of the site, the overhead was clear and something had to be done about keeping recompiling tag libraries over and over. The first attempt was the following script:

#!/bin/bash
echo “===============================================================” >> /tmp/compile.log
echo “$$ $PPID : $*” >> /tmp/compile.log
filename=`echo $4| cut -d’@’ -f 2`
javafile=`tail -1 $filename`
filet=`echo $javafile| cut -d’.’ -f 1`
classfile=”$filet.class”
ffname=`echo $classfile| awk -F/ ‘{print $NF}’`
echo “Checking if $classfile exists” >> /tmp/compile.log
if [ ! -s "$classfile" ]
then
echo “Must compile: $classfile”>>/tmp/compile.log
jout=`/opt/app/oracle/product/as10g/jdk/bin/bjavac -J-Djavac.pipe.output=true $1 $2 $3 $4 $5 $6 $7 $8 2>>/tmp/compile.log`
else
echo “Skipping $classfile” >>/tmp/compile.log
fi
echo “Done, exit code: $?”>>/tmp/compile.log

However Ojspc always terminated with a JspParseException. It didn’t like me skipping class files when it was necessary, pitty. After looking further through the Ojspc.jar files I noticed timestamps of the class files were important to please Ojspc, so we wrote another little script that fiddles with the timestamp of the .class file. The “else” branch in our above script became:

echo “Skipping $classfile” >>/tmp/compile.log
java  FileUtil $classfile>>/tmp/compile.log

The java FileUtil program fiddled with the timestamps of the already generated .class file and added 10000 msecs to the lastmodified time. Hence ojspc was always happy. The FileUtil tool looked like this:

import java.io.File;
import java.util.Date;

public class FileUtil {

public void changeFiletime(String filename) {

File fileToChange = new File(filename);

//Check time of the file/directory
Date filetime = new Date(fileToChange.lastModified());
System.out.println(filetime.toString());

if (fileToChange.setLastModified(fileToChange.lastModified()+10000))
System.out.println(“Successfile+10000!”);
else
System.out.println(“Failed!”);

//Check time again
filetime = new Date(fileToChange.lastModified());
System.out.println(filetime.toString());

}

public static void main(String[] args) {
FileUtil fileutil = new FileUtil();
fileutil.changeFiletime(args[0]);
}
}

Ojspc noticed the timestamp of the skipped .class file had changed and it was happy again, no more errors and the compilation times for our project dropped from 2 hours to 20 minutes. With all the documentation in hand and a workaround ready … it was time to open up a support request at Oracle Support. Following SR was created:

SR 7395808.994: OJSPC Batch translation keeps recompiling tag libraries was opened at Oracle Metalink.

Several weeks later a bug acknowledgement was released and after another while I received a temporary patch for ojspc.jar which works against 10.1.3.3.0. You can follow the bug process in following Bug report:

BUG 8418503 – OJSPC COMPILES THE SAME TAG CLASSES REPEATEDLY WITHOUT REASON

The patched ojspc.jar skips the compilation of .class files which already have been compiled, with the overhead gone from my workaround scripts, compile times dropped further to 7 minutes.

We have been working with these Oracle compiled builds now for over several months and have not encountered any problems. If you need to try the temporary patch contact me.

The fix is expected to be released in the patch-set for 10.1.3.5.

Comments are closed.