Mailing-List: contact users-help@tomcat.apache.org; run by ezmlm
Precedence: bulk
Reply-To: "Tomcat Users List" <users@tomcat.apache.org>
Received-SPF: neutral (athena.apache.org: local policy)
Message-ID: <4A50BA2B.50004@christopherschultz.net>
Date: Sun, 05 Jul 2009 10:35:23 -0400
From: Christopher Schultz <chris@christopherschultz.net>
User-Agent: Mozilla/5.0 (Windows; U; Windows NT 6.0; en-US;
 rv:1.9.1b3pre) Gecko/20090223 Thunderbird/3.0b2
MIME-Version: 1.0
To: Tomcat Users List <users@tomcat.apache.org>
Subject: Re: Response Time in Jasper Logs
References: <768FEA3F936926468F594E3CA7741FE8018EEFA0@ipa-vault.nvipa.com>
In-Reply-To: <768FEA3F936926468F594E3CA7741FE8018EEFA0@ipa-vault.nvipa.com>
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Eric,

On 7/5/2009 10:07 AM, Robinson, Eric wrote:
> That's very helpful, Chris.
>  
>> The bytes are not guaranteed to have arrived at the client by the time
>> the valve computes the elapsed time.
> 
> Right, but is it generally correct to say that the response time value
> represents the time from when the request was received to the time the
> response was transmitted on the wire? 

Roughly. Tomcat sets up the request and response objects and then
delegates to the first-configured Valve (which may be something other
than you think it is, depending on your configuration). Throw an
exception in your servlet code and read the stack trace to see all the
things that are being run: if nothing else, you'll gain an appreciation
for how must stuff is being done during request processing.

There is no guarantee that the /entire/ request has been received by the
time the timer starts. But, if your servlet reads all the input from the
client, that time /will/ be counted in the timing (because your servlet
will block waiting for all the data to arrive). It's not possible to
tell if /any/ of the response data has been transmitted... the best your
servlet can do is to flush the response and hope that the data is
delivered to the client is a reasonable time.

Your question makes me think that perhaps what you're seeing is a
timing-out keep-alive request: your client is sending a keep-alive
request to Tomcat which fulfills the first HTTP request coming-in on the
TCP connection, but then the client does not make any more requests, and
doesn't tell the server to close the connection. Both the client and the
server wait for a while until the server gets bored (really a
configurable timeout) and closes the connection.

You might want to put the "Connection" header into the access log to see
how many keep-alive requests you receive (my guess is that /most/ of
them are keep-alive, but it might give you some good information). I'm
not sure if it's possible to get Tomcat to report the time a connection
is held open across requests (each individual HTTP request, even on a
keep-alive connection) may/will be handled by a separate thread, so your
webapp sees everything as individual requests.

- -chris
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.9 (MingW32)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/

iEYEARECAAYFAkpQuioACgkQ9CaO5/Lv0PAWGACcDHkOSSbUnkU7jVfhQHgvgZs0
AOkAn1Knoa8bd8UV7mZN8J74JXfJWpu0
=WaR5
-----END PGP SIGNATURE-----

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