Measuring response time Apache request

Measuring response time Apache request

am 24.05.2011 17:30:33 von Marco

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

Re: Measuring response time Apache request

am 24.05.2011 17:35:38 von Adam Prime

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

Re: Measuring response time Apache request

am 24.05.2011 17:42:19 von Marco

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

Re: Measuring response time Apache request

am 24.05.2011 18:19:40 von torsten.foertsch

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

Re: Measuring response time Apache request

am 24.05.2011 18:20:23 von aw

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)

Re: Measuring response time Apache request

am 24.05.2011 18:50:24 von torsten.foertsch

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

Re: Measuring response time Apache request

am 24.05.2011 19:02:50 von Marco

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




http-equiv="Content-Type">



Il 24/05/2011 18.19, Torsten Förtsch ha scritto:

type="cite">
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--

Re: Measuring response time Apache request

am 24.05.2011 20:11:31 von torsten.foertsch

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

Re: Measuring response time Apache request

am 24.05.2011 20:21:55 von Marco

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!!!!!!!!!!!

Re: Measuring response time Apache request

am 24.05.2011 20:24:04 von aw

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.
:-)

Re: Measuring response time Apache request

am 25.05.2011 02:29:24 von Cosimo Streppone

On Wed, 25 May 2011 02:20:23 +1000, André Warnier w=
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

Re: Measuring response time Apache request

am 25.05.2011 16:41:40 von Marco

Il 25/05/2011 2.29, Cosimo Streppone ha scritto:
> On Wed, 25 May 2011 02:20:23 +1000, André Warnier wrote:
>
>> 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!!!!