Friday, January 07, 2005
Tomcat JSP Precompilation is SLOW!!
Here at Rojo we have recently started precompiling all of our JSPs to improve both the speed and reliability of our system on production servers. We have about 200 JSP files, which is a large web app but not necessarily gargantuan. The entire JSP compilation process, using Ant and the jasper2 ant task, takes about 30 minutes! This is far too long. I mean, there are systems that are doing more than just compiling text, such as advanced 3D graphics and speech recognition, that are far faster than Tomcat's JSP compilation.
I've been working on solving this problem, but to no avail, which is why I'm posting this to see if there is a solution in the blogosphere. Here's what I've done so far:
I've been working on solving this problem, but to no avail, which is why I'm posting this to see if there is a solution in the blogosphere. Here's what I've done so far:
- Switched from JspC to Eclipse's JDT compiler by moving from Tomcat 5.0 to Tomcat 5.5.4, which replaces JspC with JDT. This resulted in no real speed improvement but JDTool is less buggy, which is nice.
- Thinking that maybe the JSP precompilation process was IO bound, I setup a 400 MB ram disk on Linux, moved our entire source tree onto that, and setup the JSP precompilation process to write into the ram disk during its operation. This resulted in no real performance improvement.
- I configured the JSP compiling process to use Jikes as its compiler, but unfortunately Jikes produced a long string of errors when attempting to compile our source code. Jikes might improve the performance, but I was not able to find out because of the difference in compilation between Jikes and the Sun JDK.
- I attached JProfiler to a running JSP precompilation process to see if there are any significant hotspots. I was expecting to find a single method that took a majority of time, such as 70% of the time was spent in a single method, due to an unoptimized data structure or tight loop; if I found this I would then be able to fix it. Unfortunately, most of the time was spent amongst several methods; there was one method that consumed 20% of the time, but spending the time optimizing and only getting a 20% improvement was not enough for me; I need more bang for the buck since engineering time is tight here. The results might be useful for Tomcat JSP developers, so I've generated some HTML reports from JProfiler: Hot Spots, Invocation Tree, Method Graph, CPU Statistics
Comments:
Links to this post:
<< Home
Just some thoughts...
Are you compiling just the 200 JSPs, or a bunch of other code at the same time? How much total JSP content (in KB) is involved? If you alter the script to only compile 100 of them, does the time taken decrease by half?
I might suspect something wrong in your build script that causes the same work to be done many times redundantly. (Should there be 70 invocations of Compiler.compile?) Or, something amiss with the build machine configuration pushing it into swapping the whole time. Is there a chance any part of the build process requires access to network resources (loading classes by net) that might be laggy?
(What is the build machine CPU/RAM? What do 'top' and various options to 'sar' show during the 30-minute build -- is the CPU maxed?)
Are you compiling just the 200 JSPs, or a bunch of other code at the same time? How much total JSP content (in KB) is involved? If you alter the script to only compile 100 of them, does the time taken decrease by half?
I might suspect something wrong in your build script that causes the same work to be done many times redundantly. (Should there be 70 invocations of Compiler.compile?) Or, something amiss with the build machine configuration pushing it into swapping the whole time. Is there a chance any part of the build process requires access to network resources (loading classes by net) that might be laggy?
(What is the build machine CPU/RAM? What do 'top' and various options to 'sar' show during the 30-minute build -- is the CPU maxed?)
Gordon, great comment. In response to your questions:
> Are you compiling just the 200 JSPs, or a bunch of other code at the same time?
Well, the Ant task compiles other things before reaching the JSP compilation point. Those tasks execute quickly; its the JSP compilation task that is the slow down.
> How much total JSP content (in KB) is involved?
Good question; I don't have an exact answer, since I'm responding to this from home, but in general I've been very surprised at the size of our generated JSP files; it seems like many of them are 1.5 to 2 MBs in size! We use lots of JSP includes, which seem to replicate the includes across every JSP rather than generating a single class that might be shared across all JSPs.
> If you alter the script to only compile 100 of them, does the time taken decrease by half?
Good idea; I will try that on Monday to see if the time is proportional to the number of JSPs
> I might suspect something wrong in your build
> script that causes the same work to be done many times
> redundantly. (Should there be 70 invocations of
> Compiler.compile?) Or, something amiss with the build
> machine configuration pushing it into swapping the
> whole time.
The 70 invocations of Compiler.compile are Java invocations rather than entire re-invocations of the JVM, so they shouldn't be too bad. We shouldn't be going into virtual memory and therefore swapping from the JProfiler results; the process doesn't seem to take that much memory since the total heap doesn't seem to be garbage collected continually. I will attach VisualGC to the process on Monday to get some more indepth results on the structure of the heap (permament generation, tenured generation, and eden generation), but my feeling is the process isn't necessarily memory bound and therefore isn't forcing things into virtual memory. We are also not using anything across the network, such as mounted drives through NFS.
> What is the build machine CPU/RAM?
Unfortunately I can't go into specifics on our machine environment, but the machine is definently loaded with enough memory and CPU power.
> What do 'top' and various options to 'sar' show during the 30-minute build -- is the CPU maxed?
Good point; I'll try running top and sar to observe the CPUs process as JSP compilation occurs.
Thanx for the help. By the way, is this Gordon from the P2P Dim Sums?
> Are you compiling just the 200 JSPs, or a bunch of other code at the same time?
Well, the Ant task compiles other things before reaching the JSP compilation point. Those tasks execute quickly; its the JSP compilation task that is the slow down.
> How much total JSP content (in KB) is involved?
Good question; I don't have an exact answer, since I'm responding to this from home, but in general I've been very surprised at the size of our generated JSP files; it seems like many of them are 1.5 to 2 MBs in size! We use lots of JSP includes, which seem to replicate the includes across every JSP rather than generating a single class that might be shared across all JSPs.
> If you alter the script to only compile 100 of them, does the time taken decrease by half?
Good idea; I will try that on Monday to see if the time is proportional to the number of JSPs
> I might suspect something wrong in your build
> script that causes the same work to be done many times
> redundantly. (Should there be 70 invocations of
> Compiler.compile?) Or, something amiss with the build
> machine configuration pushing it into swapping the
> whole time.
The 70 invocations of Compiler.compile are Java invocations rather than entire re-invocations of the JVM, so they shouldn't be too bad. We shouldn't be going into virtual memory and therefore swapping from the JProfiler results; the process doesn't seem to take that much memory since the total heap doesn't seem to be garbage collected continually. I will attach VisualGC to the process on Monday to get some more indepth results on the structure of the heap (permament generation, tenured generation, and eden generation), but my feeling is the process isn't necessarily memory bound and therefore isn't forcing things into virtual memory. We are also not using anything across the network, such as mounted drives through NFS.
> What is the build machine CPU/RAM?
Unfortunately I can't go into specifics on our machine environment, but the machine is definently loaded with enough memory and CPU power.
> What do 'top' and various options to 'sar' show during the 30-minute build -- is the CPU maxed?
Good point; I'll try running top and sar to observe the CPUs process as JSP compilation occurs.
Thanx for the help. By the way, is this Gordon from the P2P Dim Sums?
Yep, same Gordon.
Wasn't so worried about the 70 invocations meaning 70 JVM launches, but since 70 != 200, it could be a symptom more work is being inadvertently repeated by the build script than necessary.
Multi-MB JSPs sound atypical and worthy of investigation (and possibly refactoring!). Are you using jsp:include or %@ include?
Wasn't so worried about the 70 invocations meaning 70 JVM launches, but since 70 != 200, it could be a symptom more work is being inadvertently repeated by the build script than necessary.
Multi-MB JSPs sound atypical and worthy of investigation (and possibly refactoring!). Are you using jsp:include or %@ include?
which include are you using (run-time or compile-time)?
i believe if you use run-time includes the size of the compiled jsps should be much smaller than if you used complie-time inlcudes exclusively.
anyhow, 1-2MB jsp class size files are really huge... i can't imagine how long the first user would have to wait when they try to access the page if you didn't precompile them.
if you look at the generated jsp source files, it's very verbose and nasty. the process of turning jsps into jsp-compilable source files is slow relative to compile times.
i like the other comment about testing with fewer jsps. if i were you i would try partitioning your one huge precompile task into many smaller ones. like say, one folder at a time (assuming your jsps are organized into sub folders or such). you can create many of these smaller precompile ant tasks that also echo out the start and end times of each task so you can see the duration of each of these mini tasks...
don't forget though, in the end, it really matters not how long it takes for precompiling, because the point is not to have users wait for pages to be compiled.
i believe if you use run-time includes the size of the compiled jsps should be much smaller than if you used complie-time inlcudes exclusively.
anyhow, 1-2MB jsp class size files are really huge... i can't imagine how long the first user would have to wait when they try to access the page if you didn't precompile them.
if you look at the generated jsp source files, it's very verbose and nasty. the process of turning jsps into jsp-compilable source files is slow relative to compile times.
i like the other comment about testing with fewer jsps. if i were you i would try partitioning your one huge precompile task into many smaller ones. like say, one folder at a time (assuming your jsps are organized into sub folders or such). you can create many of these smaller precompile ant tasks that also echo out the start and end times of each task so you can see the duration of each of these mini tasks...
don't forget though, in the end, it really matters not how long it takes for precompiling, because the point is not to have users wait for pages to be compiled.
Brad,
Your profile results are not complete. I ran into the a similar issue when debugging a weblogic related issue. JProfiler by default excludes several packages from being profiled like several java packages and weblogic packages.
In your invocation tree, you'll notice that after the top level entry of 100%, you only have a 75% invocation entry. Where is the remaining 25% being consumed? Could be some tomcat classes that are being exlcuded by JProfiler.
Before capturing statistics, turn on profiling for all classes in JProfiler. You may find the silver bullet.
In my case, I did find the root cause with Weblogic. By default for each web request, it was always checking to see if any servlet or servlet filter class was updated and this turned out to be very I/O intensive. I found the appropriate flag to change this behavior.
Sanjiv
Your profile results are not complete. I ran into the a similar issue when debugging a weblogic related issue. JProfiler by default excludes several packages from being profiled like several java packages and weblogic packages.
In your invocation tree, you'll notice that after the top level entry of 100%, you only have a 75% invocation entry. Where is the remaining 25% being consumed? Could be some tomcat classes that are being exlcuded by JProfiler.
Before capturing statistics, turn on profiling for all classes in JProfiler. You may find the silver bullet.
In my case, I did find the root cause with Weblogic. By default for each web request, it was always checking to see if any servlet or servlet filter class was updated and this turned out to be very I/O intensive. I found the appropriate flag to change this behavior.
Sanjiv
Unless it needs to be a clean build, have your build script leave intermediate files around where it can re-use them if it detects the sources aren't dirty.
If you do that, preserving generated .java and compiled .class files, then you just need to make sure that timestamps are rolled back on jsp's whose contents haven't changed.
And if you do a static import, tomcat should be smart enough to check timestamps on imported resources.
If you do that, preserving generated .java and compiled .class files, then you just need to make sure that timestamps are rolled back on jsp's whose contents haven't changed.
And if you do a static import, tomcat should be smart enough to check timestamps on imported resources.
Our JSP compilation is also terribly (and consistently) slow. This affects not only precompilation but also compilation.
The slowness is visible even if you simply update a single JSP and hit the page again-- several seconds just to compile the page.
Did you ever find any solutions for this?
The slowness is visible even if you simply update a single JSP and hit the page again-- several seconds just to compile the page.
Did you ever find any solutions for this?
We'd love to help. Have you tried Tomcat 5.5.12 yet? It includes an improvement to precompilation of many JSP files that was done as a Google Summer of Code project. Give it a shot and let us know (dev@tomcat.apache.org) if things have improved.
Did you ever figure this one out? I encountered this when randomly looking for something else, and I have to tell you, I routinely compile 500+ .JSP files and it takes less than 5 minutes. This is with Jasper2 shipped with Tomcat 5.0.28 on a 2GHZ machine with 1 GB RAM.
I'm really curious about this; e-mail me (I think my posting should reveal my e-mail address) if you have more information. I'd be glad to share with you my ant build script if it would help.
Post a Comment
I'm really curious about this; e-mail me (I think my posting should reveal my e-mail address) if you have more information. I'd be glad to share with you my ant build script if it would help.
Links to this post:
<< Home
Subscribe to Posts [Atom]