tomcat-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Sam Hokin <...@ims.net>
Subject Re: very slow class loading on initial JSP/servlet request after restart
Date Wed, 25 Feb 2009 21:54:18 GMT
NEW DISCOVERY - using a wildcard package import results in a much longer response delay!

I've taken Mark's suggestion that I import individual classes rather than importing all with
a wildcard to see if a 
particular class is slowing down classloading.  It turns out that it's the WILDCARD itself
that is causing most of the 
delay!

If I request the following "wildcard import" JSP:

<%@ page import="java.util.Date" %>
<%@ page import="net.ims.jcms.*" %> 

<%
java.util.Date endDate = new java.util.Date();
out.println(endDate.toString());
%>

it responds in 49 seconds, consistently, over several different tries (renaming the file each
time to incur the delay). 
  That includes on-the-fly compilation.

If I request a JSP that imports EVERY class in net.ims.jcms explicitly (it's a lot of lines,
so truncated below):

<%@ page import="java.util.Date" %>
<%@ page import="net.ims.jcms.AccessRole" %> 

<%@ page import="net.ims.jcms.AccessRoleException" %> 

<%@ page import="net.ims.jcms.AccessUser" %> 

<%@ page import="net.ims.jcms.AccessUserException" %> 

... a bunch more here ...
<%@ page import="net.ims.jcms.UtilityLink" %>
<%@ page import="net.ims.jcms.ValidationException" %>
<%
java.util.Date endDate = new java.util.Date();
out.println(endDate.toString());
%>

it responds in 3 seconds, consistently (with renaming), which isn't as fast as it should be,
but it's way faster than 49 
seconds.

I have no idea why a wildcard package import differs from importing explicit classes (from
the same JAR), so I don't 
know what this is telling us, but it sure seems to be significant!  I have not been able to
get lsof to display any 
files related to these requests, I expect they open and close too quickly for me to catch
it.

I have run strace during a request of a wildcard import JSP (test7.jsp) on a standalone Tomcat
instance so that I don't 
have lines from other requests.  The request is made at 15:24:09, and the response came at
15:24:58.  I've included the 
strace lines from that time range here:

http://ims.net/media/strace-test-wildcard.txt

You can see the read call on the HTTP GET request on the sixth line.  The HTTP 200 response
is in a write call near the 
bottom.  Presumably everything that happened during the 49 seconds is recorded here.  You
can see that the .java file 
has been opened within a second,

2498  15:24:09 open("/usr/local/tomcat-2/work/Catalina/test.ims.net/_/org/apache/jsp/test7_jsp.java",

O_WRONLY|O_CREAT|O_TRUNC|O_LARGEFILE, 0666) = 62 <0.000065>

and the compiled class is opened at 15:24:58,

2498  15:24:58 open("/usr/local/tomcat-2/work/Catalina/test.ims.net/_/org/apache/jsp/test7_jsp.class",

O_WRONLY|O_CREAT|O_TRUNC|O_LARGEFILE, 0666) = 62 <0.000064>

I have no idea how to interpret all the wheel-spinning that goes on in between.

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Mime
View raw message