Measuring response time Apache request
am 24.05.2011 17:30:33 von MarcoHi all,
I want to get the response time that Apache spends to serve a request
(from post-read-request phase to the response phase).
Any idea?
Thanks
Hi all,
I want to get the response time that Apache spends to serve a request
(from post-read-request phase to the response phase).
Any idea?
Thanks
On 11-05-24 11:30 AM, marco wrote:
> Hi all,
> I want to get the response time that Apache spends to serve a request
> (from post-read-request phase to the response phase).
> Any idea?
>
> Thanks
I'm pretty sure there are messages buried in the archives (from torsten)
showing how to do this with $r->push_handlers and Time::HiRes (or
something along those lines). It's not really that complicated though,
you basically just have a PostReadRequestHandler that uses push_handlers
to push a handler into every phase that just logs the current time, or
whatever it is you want to log.
Adam
Il 24/05/2011 17.35, Adam Prime ha scritto:
> On 11-05-24 11:30 AM, marco wrote:
>> Hi all,
>> I want to get the response time that Apache spends to serve a request
>> (from post-read-request phase to the response phase).
>> Any idea?
>>
>> Thanks
>
> I'm pretty sure there are messages buried in the archives (from
> torsten) showing how to do this with $r->push_handlers and Time::HiRes
> (or something along those lines). It's not really that complicated
> though, you basically just have a PostReadRequestHandler that uses
> push_handlers to push a handler into every phase that just logs the
> current time, or whatever it is you want to log.
>
> Adam
>
>
Hi Adam,
I'm in this list only since 2 weeks. Can you tell me where can I find
this mails?
Thanks a lot.
Best Regards
On Tuesday, May 24, 2011 17:30:33 marco wrote:
> I want to get the response time that Apache spends to serve a request=20
> (from post-read-request phase to the response phase).
PerlPostReadRequestHandler "sub { \
use Time::HiRes(); \
use Apache2::RequestUtil(); \
$_[0]->pnotes->{starttime}=3DTime::HiRes::time; \
0; \
}"
Then in the PerlResponseHandler you can do:
$elapsed=3DTime::HiRes::time-$r->pnotes->{starttime};
Torsten Förtsch
=2D-=20
Need professional modperl support? Hire me! (http://foertsch.name)
Like fantasy? http://kabatinte.net
marco wrote:
> Il 24/05/2011 17.35, Adam Prime ha scritto:
>> On 11-05-24 11:30 AM, marco wrote:
>>> Hi all,
>>> I want to get the response time that Apache spends to serve a request
>>> (from post-read-request phase to the response phase).
>>> Any idea?
>>>
>>> Thanks
>>
>> I'm pretty sure there are messages buried in the archives (from
>> torsten) showing how to do this with $r->push_handlers and Time::HiRes
>> (or something along those lines). It's not really that complicated
>> though, you basically just have a PostReadRequestHandler that uses
>> push_handlers to push a handler into every phase that just logs the
>> current time, or whatever it is you want to log.
>>
>> Adam
>>
>>
> Hi Adam,
> I'm in this list only since 2 weeks. Can you tell me where can I find
> this mails?
> Thanks a lot.
>
To answer you last question :
Go to : http://perl.apache.org/
On the left side, there is an item : Mailing lists
This leads you to the : mod_perl Users mailing list
This leads you to the : Searchable archives
where you have a choice of searchable archives.
and have a look for example at "marc.theaimsgroup.com"
Apart from that, and for the main issue :
Is it not easier to just read the Apache access log a posteriori, and filter the lines
which you need ?
With the appropriate LogFormat, you can have the microseconds needed for each request.
See : http://httpd.apache.org/docs/2.2/mod/mod_log_config.html#for mats
(parameter %D)
e.g.
LogFormat "%a - %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\" %D" combined_ip
CustomLog /var/log/apache2/somehost/access.log combined_ip
Sample log line with the above format (server name changed for privacy) :
192.168.193.11 - U367532 [24/May/2011:17:49:05 +0200] "POST /starweb/OPAC/servlet.starweb
HTTP/1.0" 200 28029
"http://somehost.mycompany.com/starweb/OPAC/servlet.starweb? path=OPAC/STARLibs_OPAC_xxx.web"
"Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 5.2; .NET CLR 1.1.4322; .NET CLR 2.0.50727;
..NET CLR 3.0.04506.648; .NET CLR 3.5.21022; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729;
..NET4.0C; .NET4.0E)" 147626
(the last number is the number of microseconds needed to process that request)
On Tuesday, May 24, 2011 18:20:23 Andr=E9 Warnier wrote:
> Is it not easier to just read the Apache access log a posteriori, and
> filter the lines which you need ?
> With the appropriate LogFormat, you can have the microseconds needed
> for each request.
With Apache2::ModLogConfig you can even install a Perl handler to be=20
called by CustomLog:
sub My::LogReceiver {
my ($r, $usec)=3D@_;
...
}
CustomLog "@perl: My::LogReceiver" "%D"
But Marco wanted PostReadRequest =3D> Response not PostReadRequest =3D> Log.
Torsten Förtsch
=2D-=20
Need professional modperl support? Hire me! (http://foertsch.name)
Like fantasy? http://kabatinte.net
This is a multi-part message in MIME format.
--------------030805090907050206060006
Content-Type: text/plain; charset=ISO-8859-1; format=flowed
Content-Transfer-Encoding: 8bit
Il 24/05/2011 18.19, Torsten Förtsch ha scritto:
> On Tuesday, May 24, 2011 17:30:33 marco wrote:
>> I want to get the response time that Apache spends to serve a request
>> (from post-read-request phase to the response phase).
> PerlPostReadRequestHandler "sub { \
> use Time::HiRes(); \
> use Apache2::RequestUtil(); \
> $_[0]->pnotes->{starttime}=Time::HiRes::time; \
> 0; \
> }"
>
> Then in the PerlResponseHandler you can do:
>
> $elapsed=Time::HiRes::time-$r->pnotes->{starttime};
>
> Torsten Förtsch
>
Hi,
I follow your suggest using Time::HiRes but I have an error when I try
to start apache. Here's my code(it is only an example):
This is the script that will be executed as response handler, but it
doesn't work because doesn't print the time.
*use strict;
use warnings;
use Time::HiRes qw(gettimeofday tv_interval);
use Apache2::RequestRec ();
use Apache2::RequestIO ();
use Apache2::Const -compile => 'OK';
sub handler{
my $r = shift;
my $start_time = [ gettimeofday ];
my $end_time = [ gettimeofday ];
my $elapsed = tv_interval($start_time,$end_time);
$r->send_http_header('text/html');
$r->print ($elapsed);
return Apache2::Const::OK;
}
1;
*
In httpd.conf file I have:
PerlPostReadRequestHandler Dir::touch #this script is well executed
PerlResponseHandler Dir::timediff #this handler (below)
is not executed!!!!!!!!!!!!!!!!!!!
why it doesn't work?
Can you help me,please?
Thanks for your answers!
--------------030805090907050206060006
Content-Type: text/html; charset=ISO-8859-1
Content-Transfer-Encoding: 7bit
On Tuesday, May 24, 2011 17:30:33 marco wrote:
I want to get the response time that Apache spends to serve a request
(from post-read-request phase to the response phase).
PerlPostReadRequestHandler "sub { \
use Time::HiRes(); \
use Apache2::RequestUtil(); \
$_[0]->pnotes->{starttime}=Time::HiRes::time; \
0; \
}"
Then in the PerlResponseHandler you can do:
$elapsed=Time::HiRes::time-$r->pnotes->{starttime};
Torsten Förtsch
On Tuesday, May 24, 2011 19:02:50 marco wrote:
> In httpd.conf file I have:
>=20
> PerlPostReadRequestHandler Dir::touch #this script is well
> executed PerlResponseHandler Dir::timediff #this
> handler (below) is not executed!!!!!!!!!!!!!!!!!!!
perhaps you forgot
SetHandler modperl
The response phase is a bit different from the other phases. The=20
"SetHandler" is needed to make apache call the perl interpreter in the=20
response phase.
Torsten Förtsch
=2D-=20
Need professional modperl support? Hire me! (http://foertsch.name)
Like fantasy? http://kabatinte.net
Il 24/05/2011 20.11, Torsten Förtsch ha scritto:
> On Tuesday, May 24, 2011 19:02:50 marco wrote:
>> In httpd.conf file I have:
>>
>> PerlPostReadRequestHandler Dir::touch #this script is well
>> executed PerlResponseHandler Dir::timediff #this
>> handler (below) is not executed!!!!!!!!!!!!!!!!!!!
> perhaps you forgot
>
> SetHandler modperl
>
> The response phase is a bit different from the other phases. The
> "SetHandler" is needed to make apache call the perl interpreter in the
> response phase.
>
> Torsten Förtsch
>
Ok i solved it, thanks a lot Torsten!!!!!!!!!!!
Torsten Förtsch wrote:
> On Tuesday, May 24, 2011 18:20:23 André Warnier wrote:
>> Is it not easier to just read the Apache access log a posteriori, and
>> filter the lines which you need ?
>> With the appropriate LogFormat, you can have the microseconds needed
>> for each request.
>
> With Apache2::ModLogConfig you can even install a Perl handler to be
> called by CustomLog:
>
>
> sub My::LogReceiver {
> my ($r, $usec)=@_;
> ...
> }
>
>
> CustomLog "@perl: My::LogReceiver" "%D"
>
> But Marco wanted PostReadRequest => Response not PostReadRequest => Log.
>
I know, but the difference is likely to be only a Muckeseckele, as they say around here.
:-)
On Wed, 25 May 2011 02:20:23 +1000, André Warnier
rote:
> marco wrote:
>> Il 24/05/2011 17.35, Adam Prime ha scritto:
>>> On 11-05-24 11:30 AM, marco wrote:
>>>> Hi all,
>>>> I want to get the response time that Apache spends to serve a reque=
st
>>>> (from post-read-request phase to the response phase).
>>>> Any idea?
> See : http://httpd.apache.org/docs/2.2/mod/mod_log_config.html#for mats=
> (parameter %D)
Hi Marco,
I also use "%D" as André suggested.
Add "%D" to your LogFormat string,
unless you need to do something in your application
with the request time, like for example
include it in a html comment.
If you're using Debian/Ubuntu, just change your LogFormat
or create a file like "/etc/apache2/conf.d/log-request-time" with:
LogFormat "%a %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i=
\" =
time:%D" combined
that should be it.
-- =
Cosimo
Il 25/05/2011 2.29, Cosimo Streppone ha scritto:
> On Wed, 25 May 2011 02:20:23 +1000, André Warnier
>
>> marco wrote:
>>> Il 24/05/2011 17.35, Adam Prime ha scritto:
>>>> On 11-05-24 11:30 AM, marco wrote:
>
>>>>> Hi all,
>>>>> I want to get the response time that Apache spends to serve a request
>>>>> (from post-read-request phase to the response phase).
>>>>> Any idea?
>
>> See : http://httpd.apache.org/docs/2.2/mod/mod_log_config.html#for mats
>> (parameter %D)
>
> Hi Marco,
>
> I also use "%D" as André suggested.
>
> Add "%D" to your LogFormat string,
> unless you need to do something in your application
> with the request time, like for example
> include it in a html comment.
>
> If you're using Debian/Ubuntu, just change your LogFormat
> or create a file like "/etc/apache2/conf.d/log-request-time" with:
>
> LogFormat "%a %l %u %t \"%r\" %>s %b \"%{Referer}i\"
> \"%{User-Agent}i\" time:%D" combined
>
> that should be it.
>
Hi,
thanks for your answer. I tried it and it works!!!!