Re: gettimeofday calls

[Greg Ames]

Greg Ames wrote:
one of the things that inhibits our SMP scalability with 
out-of-the-box Linux kernels is contention on the dcache spinlock. 
oopss/dcache/dentry_cache/
The LTC guys use a dcache RCU (read-copy-update) patch 
same here
Greg

Re: gettimeofday calls

[David Hill]

 I had a couple of inputs here : I was talking to our specweb person,
and he
 had the following views :

 1. most modern day os'es cache the files, and not do a disk io for
every
 single file request. (duh !!.)

Part of the design of specweb was to make it difficult (but not
imposible) to cache the doc tree. As your ops scale up, so does the
size of the doc tree. If you want to test caching use ab (apache
bench) or flood  :-) This ususally mean that you want a lot of memory,
my borrowed test machine had 8gb

 3. caching the fd's would be more than sufficient (than caching the
 contents).

This helps avoid the disk tree traversal and the open, so yes, it
would cut down on a lot of processing.

 4. on hp-ux, eliminating the stat/fstat would not make a lot of
difference..
 I dont know about other os'es - but, based on his logic, since the
fd for
 that file is already available, fstat should not take a lot of time.

I would be surprised if the stat/fstat removal would make no
difference but it might be small. Any system call is a context switch
which adds up.

Of course on a suped up box here, running full out, I was seeing
apache use ~4% of the cpu which says that savings in apache (user
space) may not add up to any significant savings...

 5. Another interesting question : why do we need the poll everytime
?.
 Instead do a accept, and if there's no request available, accept
would
 return EWOULDBLOCK. For a benchmark, accept would *never* return
 EWOULDBLOCK, and for a normal server, it's okay - because the server
is
 idle.

You don't want a busy wait state which is what you would need with
ewouldblock. chews up lots of cpu time that someone else might
want. Poll is a better general solution to the problem which is why
apache does it.

Dave

Re: gettimeofday calls

[Greg Ames]

MATHIHALLI,MADHUSUDAN (HP-Cupertino,ex1) wrote:
I had a couple of inputs here : I was talking to our specweb person, and he
had the following views :
1. most modern day os'es cache the files, and not do a disk io for every
single file request. (duh !!.)
yep.  Yesterday I powered up wimp for the first time in ages and did a 
mini-SPECweb experimental run in preparation for fiddling with the stat() in 
mod_specweb99.  I got really horrible results at first and couldn't figure out 
what was wrong.  It turned out that I just needed to warm up the kernel's disk 
cache more.  The results got 50% better after an hour or so.

2. when doing writes, do a 64M block writes, instead of write to disk every
time.. (Lazy write)
I would hope a smart file system/kernel would take care of that for us.
3. caching the fd's would be more than sufficient (than caching the
contents). 
yep, it actually would be better for big files because we can do sendfile.  If 
your NIC has hardware checksum, a smart kernel/device driver can just do DMA 
from the file cache.  But how many fd's can you cache?

4. on hp-ux, eliminating the stat/fstat would not make a lot of difference..
I dont know about other os'es - but, based on his logic, since the fd for
that file is already available, fstat should not take a lot of time.
Some of my buddies in IBM's Linux Technology Center who run SPECweb99 say that 
one of the things that inhibits our SMP scalability with out-of-the-box Linux 
kernels is contention on the dcache spinlock.  That comes into play every time 
you do a syscall and pass a file path that the kernel has to walk.  So open()s 
and stat()s are the prime suspects.

I'm wondering why we need the stat() at all in mod_specweb99?  It looks like the 
only thing we use from it is s.size.  But IIRC the sendfile() syscall is happy 
if you give it a size of zero, which means send the whole thing.  This obviously 
needs to be tested to see how our code reacts to EAGAIN + size == 0.  If we 
can't get rid of it altogether, I would prefer to use fstat() a.k.a. 
apr_file_info_get()

The LTC guys use a dcache RCU (read-copy-update) patch that eliminates the 
spinlock contention, but I doubt if a high percentage of our users are willing 
to build custom kernels.  The kernel still has to walk the file path, lock or no 
 lock.

5. Another interesting question : why do we need the poll everytime ?.
Instead do a accept, and if there's no request available, accept would
return EWOULDBLOCK. 
If your box supports SINGLE_LISTEN_UNSERIALIZED_ACCEPT, you shouldn't have any 
polls before the accepts, barring bugs.  SPECweb99 does a lot of keepalive 
requests, and we poll for new data between requests on the same connection. 
That's probably what you're seeing.

Greg

Re: gettimeofday calls

[David Hill]

  1. most modern day os'es cache the files, and not do a disk io for
every
  single file request. (duh !!.)

 yep.  Yesterday I powered up wimp for the first time in ages and did
a
 mini-SPECweb experimental run in preparation for fiddling with the
stat() in
 mod_specweb99.  I got really horrible results at first and couldn't
figure out
 what was wrong.  It turned out that I just needed to warm up the
kernel's disk
 cache more.  The results got 50% better after an hour or so.

When our specweb guys were whacking Zeus they would first run a
program that would walk the file set to try and fill up the cache.
This made a big difference with Zeus, but I never saw much of a
change, but then again I was shooting for a much lower specweb.

Dave

Re: gettimeofday calls

[Greg Ames]

David Hill wrote:
When our specweb guys were whacking Zeus they would first run a
program that would walk the file set to try and fill up the cache.
hey, I like that idea!  I wonder if:
find /spec_docroot/file_set/ -type f | xargs cat  /dev/null
...will do the job?  I'll give it a try.
Greg

Re: gettimeofday calls

[David Hill]

  When our specweb guys were whacking Zeus they would first run a
  program that would walk the file set to try and fill up the cache.

Zues had some sort of internal cache that needed to be warmed on a
per-process basis (they would run with one process per cpu), as well
as warming the read cache in the kernel.


 hey, I like that idea!  I wonder if:

 find /spec_docroot/file_set/ -type f | xargs cat  /dev/null

 ...will do the job?  I'll give it a try.

You may want to restrict yourself to the smaller classes depends
on your memory. If you don't have enough, you will just shove
everything through the kernel into the bit bucket :-) Other than
that - yes it should :-)

Dave

Re: gettimeofday calls

[Greg Ames]

Greg Ames wrote:
Bill Stoddard wrote:

 Why not use mod_file_cache? 
On my wimpy 200MHz server, the SPEC file_set contains 5760 files and 
uses .8G of disk.  On more modern servers, the size of the file_set goes 
up in proportion to the number of conforming connections you hope to 
push thru it, so figure 57,600 files and 8G of space on a 2GHz server.  
8G isn't going to fit into one process's virtual memory on a Pentium; 
caching 57,600 fd's is going to be a challenge too, as I think Madhu is 
finding out.
One way to make this easier might be to cache as many of the smaller files in 
memory as will reasonably fit, then caching the file descriptors for the 
remaining files.  If that still isn't practical, you could fagettabout caching 
the very biggest files since they will take a long time to serve no matter what.

On the hypothetical 2GHz server, if I cached all the class0_* thru class2_* 
(smallest) files in memory, that would eat about .8G per process, leaving 14,400 
larger class3_* files to deal with somehow.

A disadvantage of caching in memory might be higher CPU usage from copying + 
checksumming data from user space to NIC buffers vs. using sendfile.  That 
probably doesn't matter for really tiny files.

Greg

RE: gettimeofday calls

[MATHIHALLI,MADHUSUDAN (HP-Cupertino,ex1)]

I had a couple of inputs here : I was talking to our specweb person, and he
had the following views :

1. most modern day os'es cache the files, and not do a disk io for every
single file request. (duh !!.)
2. when doing writes, do a 64M block writes, instead of write to disk every
time.. (Lazy write)
3. caching the fd's would be more than sufficient (than caching the
contents). 
4. on hp-ux, eliminating the stat/fstat would not make a lot of difference..
I dont know about other os'es - but, based on his logic, since the fd for
that file is already available, fstat should not take a lot of time.

5. Another interesting question : why do we need the poll everytime ?.
Instead do a accept, and if there's no request available, accept would
return EWOULDBLOCK. For a benchmark, accept would *never* return
EWOULDBLOCK, and for a normal server, it's okay - because the server is
idle.

-Madhu

-Original Message-
From: Greg Ames [mailto:[EMAIL PROTECTED]
Sent: Tuesday, January 28, 2003 11:05 AM
To: [EMAIL PROTECTED]
Subject: Re: gettimeofday calls


Greg Ames wrote:
 Bill Stoddard wrote:

  Why not use mod_file_cache? 
 
 On my wimpy 200MHz server, the SPEC file_set contains 5760 files and 
 uses .8G of disk.  On more modern servers, the size of the 
file_set goes 
 up in proportion to the number of conforming connections you hope to 
 push thru it, so figure 57,600 files and 8G of space on a 
2GHz server.  
 8G isn't going to fit into one process's virtual memory on a 
Pentium; 
 caching 57,600 fd's is going to be a challenge too, as I 
think Madhu is 
 finding out.

One way to make this easier might be to cache as many of the 
smaller files in 
memory as will reasonably fit, then caching the file 
descriptors for the 
remaining files.  If that still isn't practical, you could 
fagettabout caching 
the very biggest files since they will take a long time to 
serve no matter what.

On the hypothetical 2GHz server, if I cached all the class0_* 
thru class2_* 
(smallest) files in memory, that would eat about .8G per 
process, leaving 14,400 
larger class3_* files to deal with somehow.

A disadvantage of caching in memory might be higher CPU usage 
from copying + 
checksumming data from user space to NIC buffers vs. using 
sendfile.  That 
probably doesn't matter for really tiny files.

Greg

Re: gettimeofday calls

[Greg Ames]

MATHIHALLI,MADHUSUDAN (HP-Cupertino,ex1) wrote:
I don't know if this has been discussed already, but I was thinking of the
following alternatives : 
1. how about the listener thread in each of the child process keeps updating
a global time variable that each of the threads can refer to ?. 
2. set the time at the begining of the process, and then each of the thread
measures the amount of time it has been running.. (Current time = startup
time + delta time).. AFAIK, the time taken to compute delta time is much
lesser than gettimeofday..
I'm a little confused.  The gettimeofday()/apr_time_now() happens in the httpd 
core AFAIK.   Brian Pane said that it's cheaper than time() on some platforms, I 
believe.  If we want to discuss alternatives to that, the discussion belongs on 
[EMAIL PROTECTED]

But then in your next post it sounds like you're experimenting with the time() 
syscalls in mod_specweb99.

Is this against the spec or something ?.
Which spec?  If you are referring to either the SPECWeb99 run rules or to 
RFC2616, neither of them dictate which syscalls you use.

Greg

Re: gettimeofday calls

[Sander Temme]

 Is this against the spec or something ?.
 
 Which spec?  If you are referring to either the SPECWeb99 run rules or to
 RFC2616, neither of them dictate which syscalls you use.

IIRC, the SPECWeb99 run rules just say that you have to treat ad expiration
correctly.

S.

-- 
Covalent Technologies [EMAIL PROTECTED]
Engineering groupVoice: (415) 856 4214
303 Second Street #375 South   Fax: (415) 856 4210
San Francisco CA 94107

   PGP Fingerprint: 7A8D B189 E871 80CB 9521  9320 C11E 7B47 964F 31D9

===
This email message is for the sole use of the intended recipient(s) and may
contain confidential and privileged information. Any unauthorized review,
use, disclosure or distribution is prohibited.  If you are not the intended
recipient, please contact the sender by reply email and destroy all copies
of the original message
===

Re: gettimeofday calls

[Greg Ames]

MATHIHALLI,MADHUSUDAN (HP-Cupertino,ex1) wrote:
I tried that, and I got back error from specweb99 stating that the responses
were not conforming. (or something like that).. 
OK, if you used r-request_time to replace the time() calls in mod_specweb99, 
you might have convert the units if the result gets sent as part of a specweb 
response or put in a file that will get sent to the client.  If it's just using 
the values internally, like when it tries to avoid a stat(), there's no need to 
convert units as long as it always deals with the same units.

r-request_time is an apr_time_t (microseconds); time() gives you seconds 
(time_t?).  There are some apr macros to do the conversions.

Now, I have a global time variable, that I set once in
specweb99_quick_handler(), 
I think that would penalize the standard (no cookie/custom ad) dynamic 
GETs...they shouldn't need any timestamp information at all.  Plus, I don't 
understand why r-request_time wouldn't work for the custom ad path.

and the other two instances, try to use it,
rather than compute again.. The thirsd time() - in the ap_log_error(), I've
put it in ifdef DEBUG :-).. Trying this out now..
Greg

Re: gettimeofday calls

[Bill Stoddard]

Infact, I tried this out yesterday (having the one global_time variable), it
gives me around 3-4% improvement. But, occasionally I do get some
un-conforming results, and I'm trying to figure out if it's because of the
time stamp.
You probably need to mutex updates to your global variable, which will 
probably suck out most of your performance gains.

Anyways, moving away from the time(), here's what I've been thinking..I'm
sure many of you have gone through this list, so, can you please give me
your feedback regarding the following :
1. Why we need to do the apr_stat() for static files each time the request
comes in - can it be done during the module_init() phase, and the values put
in a array of some sort. ?.
Files change. Why not use mod_file_cache? It will (or should if it does 
not have a bug) eliminate the stat.  Or we could  spend time rewriting 
code to just do an open (followed by a less expensive fstat) rather than 
a stat/open.

Bill

RE: gettimeofday calls

[MATHIHALLI,MADHUSUDAN (HP-Cupertino,ex1)]

-Original Message-
From: Bill Stoddard [mailto:[EMAIL PROTECTED]
[snip]
You probably need to mutex updates to your global variable, which will 
probably suck out most of your performance gains.

That is correct.. The assumption I had is : timestamp is done once per
request, and since there are multiple requests coming in per second, it
really should not matter if the next request overwrites the older value
(it's afterall within a second resolution).


Anyways, moving away from the time(), here's what I've been 
thinking..I'm
sure many of you have gone through this list, so, can you 
please give me
your feedback regarding the following :

1. Why we need to do the apr_stat() for static files each 
time the request
comes in - can it be done during the module_init() phase, and 
the values put
in a array of some sort. ?.

Files change. Why not use mod_file_cache? It will (or should 
if it does 
not have a bug) eliminate the stat.  Or we could  spend time rewriting 
code to just do an open (followed by a less expensive fstat) 
rather than 
a stat/open.

That is the intent. But I have a problem there.. When I use the
mod_file_cache, it opens up the fd's starting from the lower end (10, 11 or
something).. And then, when we receive a request, the network layer starts
searching from the bottom for a open fd - it scans the whole list, finds one
at 6 or something like that, and then apache doesn't like it.
Is there some sort of mod_file_cache can use fd's only more than 1 or
something like that ?.. 

-Madhu

Re: gettimeofday calls

[Greg Ames]

MATHIHALLI,MADHUSUDAN (HP-Cupertino,ex1) wrote:
  I was referring to the time(), and thinking of
alternative ways of replacing the time() call.

I did that (without using the macros) - but didn't see much difference
though.. I think I was banging my head against the wall yesterday - by tring
to remove something, but introducing something else complex :(.. 
cool, thanks.  Not sure why it didn't work, but whatever.
Infact, I tried this out yesterday (having the one global_time variable), it
gives me around 3-4% improvement. But, occasionally I do get some
un-conforming results, and I'm trying to figure out if it's because of the
time stamp.
OK, I'm thinking of a compromise here...
1.  Let's get your version working right, i.e., no complaints from the client
2.  then let's see if we can move the init of global_time out of 
specweb99_quick_handler() to do_cadget() so we don't have any time overhead for 
the other types of requests that don't need it
3.  then let's see if we can set global_time by feeding r-request_time thru a 
macro, rather than using a syscall

So do you want to post a patch for your version with the global_time?  I'll be 
happy to take a look at it and see if I can help figure out why the client is 
complaining.

2. mmap the post.log, and since the post.log is requested only once, it can
be closed  re-mapped when the request comes in.
That might work.  I'm thinking that moving it to shared memory would be the 
ultimate cheap way to do it though.

Greg
p.s. something you might want to try is to change the workload mix parameters 
(DYNAMIC_CONTENT, DYNAMIC_POST, etc) in the rc file so that you get 100% static 
requests, 100% POSTs, 100% CAD GETs, or 100% standard dynamic GETs.  The last 
time I did that, the CAD GETs were the slowest of all and std dynamic GETs were 
faster than static files, believe it or not.  But then I got rid of a couple of 
strlen's in the CAD path, so I don't know which part of the workload is the 
slowest at the moment (other than CGI, and they are always going to suck).

Re: gettimeofday calls

[Greg Ames]

Bill Stoddard wrote:
1. Why we need to do the apr_stat() for static files each time the 
request
comes in - can it be done during the module_init() phase, and the 
values put
in a array of some sort. ?.

Files change. Why not use mod_file_cache? It will (or should if it does 
not have a bug) eliminate the stat.  
On my wimpy 200MHz server, the SPEC file_set contains 5760 files and uses .8G of 
disk.  On more modern servers, the size of the file_set goes up in proportion to 
the number of conforming connections you hope to push thru it, so figure 57,600 
files and 8G of space on a 2GHz server.  8G isn't going to fit into one 
process's virtual memory on a Pentium; caching 57,600 fd's is going to be a 
challenge too, as I think Madhu is finding out.

   Or we could  spend time rewriting 
code to just do an open (followed by a less expensive fstat) rather than 
a stat/open.
That sounds like a winner, especially for the standard dynamic GETs handled 
within mod_specweb99.  At ApacheCon, OtherBill mentioned that Win32 does have 
something like fstat and that we have apr support for it already.

But for static GETs, that means changing directory_walk, apr, and/or maybe the 
handlers.  I suppose it could be done if you hid the fd in apr somewhere until 
the apr_file_open came along.

Greg

gettimeofday calls

[MATHIHALLI,MADHUSUDAN (HP-Cupertino,ex1)]

Hi,
The following is the tusc output of httpd (2.0.43) + mod_specweb99.c
on HP-UX.. Almost every single request has a gettimeofday system call - is
there any way to avoid it ?. I haven't searched the archives if this
question has already been asked several times - so, please excuse me here..

-Madhu

{72114} poll(0x6fd88910, 1, 12) .. = 1
{72114} read(149, G E T   / ? / f i l e _ s e t / .., 8000) = 159
{72114} gettimeofday(0x6fd88448, NULL) ... = 0
{72114} time(NULL) ... = 1043344112
{72114} time(NULL) ... = 1043344112
{72114} time(NULL) ... = 1043344112
{72114} stat(/opt/apache2/htdocs//file_set/dir00016/class1_8, 0x6fd885c8)
= 0
{72114} open(/opt/apache2/htdocs//file_set/dir00016/class1_8, O_RDONLY,
0666) 
= 43
{72114} read(43,   9 2 1 6   f i l e _ s .., 9216) = 9216
{72114} writev(149, 0x6fd88988, 4) ... = 9803
{72114} read(149, 0x40288078, 8000) .. ERR#11 EAGAIN
{72114} write(8, 1 9 2 . 1 6 8 . 3 . 2   [ 2 3 / .., 95) = 95
{72114} close(43)  = 0
{72114} poll(0x6fd88910, 1, 12) .. = 1
{72114} read(149, G E T   / f i l e _ s e t / d i .., 8000) = 70
{72114} gettimeofday(0x6fd88448, NULL) ... = 0
{72114} stat(/opt/apache2/htdocs/file_set/dir00047/class1_0, 0x6fd88548) =
0
{72114} open(/opt/apache2/htdocs/file_set/dir00047/class1_0, O_RDONLY, 0)
= 55
{72114} read(149, 0x40288078, 8000) .. ERR#11 EAGAIN
{72114} sendfile(149, 55, 0, 1024, 0x6fd88688, 0)  = 1289
{72114} write(8, 1 9 2 . 1 6 8 . 3 . 2   [ 2 3 / .., 93) = 93
{72114} poll(0x6fd88910, 1, 12) .. = 1
{72114} read(149, G E T   / f i l e _ s e t / d i .., 8000) = 70
{72114} gettimeofday(0x6fd88448, NULL) ... = 0
{72114} stat(/opt/apache2/htdocs/file_set/dir9/class0_3, 0x6fd88548) =
0
{72114} open(/opt/apache2/htdocs/file_set/dir9/class0_3, O_RDONLY, 0)
= 59
{72114} read(149, 0x4038c098, 8000) .. ERR#11 EAGAIN
{72114} sendfile(149, 59, 0, 409, 0x6fd88688, 0) . = 673
{72114} write(8, 1 9 2 . 1 6 8 . 3 . 2   [ 2 3 / .., 92) = 92
{72114} poll(0x6fd88910, 1, 12) .. = 1
{72114} read(149, G E T   / f i l e _ s e t / d i .., 8000) = 70
{72114} gettimeofday(0x6fd88448, NULL) ... = 0
{72114} stat(/opt/apache2/htdocs/file_set/dir0/class1_2, 0x6fd88548) =
0
{72114} open(/opt/apache2/htdocs/file_set/dir0/class1_2, O_RDONLY, 0)
= 76
{72114} read(149, 0x40288078, 8000) .. ERR#11 EAGAIN
{72114} sendfile(149, 76, 0, 3072, 0x6fd88688, 0)  = 3336
{72114} write(8, 1 9 2 . 1 6 8 . 3 . 2   [ 2 3 / .., 93) = 93

Re: gettimeofday calls

[Greg Ames]

MATHIHALLI,MADHUSUDAN (HP-Cupertino,ex1) wrote:
	The following is the tusc output of httpd (2.0.43) + mod_specweb99.c
on HP-UX.. Almost every single request has a gettimeofday system call - is
there any way to avoid it ?. 
The GET /file_set/* requests are just plain ol' static files served by the httpd 
core, so I think the gettimeofday is due to:

r-request_time = apr_time_now();
...line 681 from server/protocol.c.  I don't see that going away in the near 
future.
OTOH, the GET /?/file_set/* is a dynamic request served by mod_specweb99.  The 
three time() syscalls there bother me.  I'm guessing that this request had a 
cookie which drives do_cadget() and friends.  Looking at code in that path I do 
see three different time calls.  One of them will go away if you select a 
quieter LogLevel...you probably have Found ad blah expire yes/no 
timestamp messages in your error log.

Off the top of my head, we could probably change mod_specweb99 to use 
r-request_time in place of the time() syscalls and make it a little faster. 
But then we will have to take into account the difference between apr_time_t's 
and seconds. :-(

Greg
{72114} poll(0x6fd88910, 1, 12) .. = 1
{72114} read(149, G E T   / ? / f i l e _ s e t / .., 8000) = 159
{72114} gettimeofday(0x6fd88448, NULL) ... = 0
{72114} time(NULL) ... = 1043344112
{72114} time(NULL) ... = 1043344112
{72114} time(NULL) ... = 1043344112
{72114} stat(/opt/apache2/htdocs//file_set/dir00016/class1_8, 0x6fd885c8)
= 0
{72114} open(/opt/apache2/htdocs//file_set/dir00016/class1_8, O_RDONLY,
0666) 
= 43
{72114} read(43,   9 2 1 6   f i l e _ s .., 9216) = 9216
{72114} writev(149, 0x6fd88988, 4) ... = 9803
{72114} read(149, 0x40288078, 8000) .. ERR#11 EAGAIN
{72114} write(8, 1 9 2 . 1 6 8 . 3 . 2   [ 2 3 / .., 95) = 95
{72114} close(43)  = 0
{72114} poll(0x6fd88910, 1, 12) .. = 1
{72114} read(149, G E T   / f i l e _ s e t / d i .., 8000) = 70
{72114} gettimeofday(0x6fd88448, NULL) ... = 0
{72114} stat(/opt/apache2/htdocs/file_set/dir00047/class1_0, 0x6fd88548) =
0
{72114} open(/opt/apache2/htdocs/file_set/dir00047/class1_0, O_RDONLY, 0)
= 55
{72114} read(149, 0x40288078, 8000) .. ERR#11 EAGAIN
{72114} sendfile(149, 55, 0, 1024, 0x6fd88688, 0)  = 1289
{72114} write(8, 1 9 2 . 1 6 8 . 3 . 2   [ 2 3 / .., 93) = 93
{72114} poll(0x6fd88910, 1, 12) .. = 1
{72114} read(149, G E T   / f i l e _ s e t / d i .., 8000) = 70
{72114} gettimeofday(0x6fd88448, NULL) ... = 0
{72114} stat(/opt/apache2/htdocs/file_set/dir9/class0_3, 0x6fd88548) =
0
{72114} open(/opt/apache2/htdocs/file_set/dir9/class0_3, O_RDONLY, 0)
= 59
{72114} read(149, 0x4038c098, 8000) .. ERR#11 EAGAIN
{72114} sendfile(149, 59, 0, 409, 0x6fd88688, 0) . = 673
{72114} write(8, 1 9 2 . 1 6 8 . 3 . 2   [ 2 3 / .., 92) = 92
{72114} poll(0x6fd88910, 1, 12) .. = 1
{72114} read(149, G E T   / f i l e _ s e t / d i .., 8000) = 70
{72114} gettimeofday(0x6fd88448, NULL) ... = 0
{72114} stat(/opt/apache2/htdocs/file_set/dir0/class1_2, 0x6fd88548) =
0
{72114} open(/opt/apache2/htdocs/file_set/dir0/class1_2, O_RDONLY, 0)
= 76
{72114} read(149, 0x40288078, 8000) .. ERR#11 EAGAIN
{72114} sendfile(149, 76, 0, 3072, 0x6fd88688, 0)  = 3336
{72114} write(8, 1 9 2 . 1 6 8 . 3 . 2   [ 2 3 / .., 93) = 93

Re: gettimeofday calls

[David Hill]

I would think that using the http request time would meet the spec and
be easier than your alternatives...

Dave
- Original Message -
From: MATHIHALLI,MADHUSUDAN (HP-Cupertino,ex1)
[EMAIL PROTECTED]
To: [EMAIL PROTECTED]
Sent: Thursday, January 23, 2003 4:05 PM
Subject: RE: gettimeofday calls


 I don't know if this has been discussed already, but I was thinking
of the
 following alternatives :
 1. how about the listener thread in each of the child process keeps
updating
 a global time variable that each of the threads can refer to ?.
 2. set the time at the begining of the process, and then each of the
thread
 measures the amount of time it has been running.. (Current time =
startup
 time + delta time).. AFAIK, the time taken to compute delta time is
much
 lesser than gettimeofday..

 Is this against the spec or something ?.

 -Madhu

 -Original Message-
 From: Greg Ames [mailto:[EMAIL PROTECTED]
 Sent: Thursday, January 23, 2003 11:19 AM
 To: [EMAIL PROTECTED]
 Subject: Re: gettimeofday calls


 MATHIHALLI,MADHUSUDAN (HP-Cupertino,ex1) wrote:

  The following is the tusc output of httpd (2.0.43) +
 mod_specweb99.c
  on HP-UX.. Almost every single request has a gettimeofday
 system call - is
  there any way to avoid it ?.

 The GET /file_set/* requests are just plain ol' static files
 served by the httpd
 core, so I think the gettimeofday is due to:

  r-request_time = apr_time_now();

 ...line 681 from server/protocol.c.  I don't see that going
 away in the near future.

 OTOH, the GET /?/file_set/* is a dynamic request served by
 mod_specweb99.  The
 three time() syscalls there bother me.  I'm guessing that this
 request had a
 cookie which drives do_cadget() and friends.  Looking at code
 in that path I do
 see three different time calls.  One of them will go away if
 you select a
 quieter LogLevel...you probably have Found ad blah expire
yes/no
 timestamp messages in your error log.

 Off the top of my head, we could probably change mod_specweb99 to
use
 r-request_time in place of the time() syscalls and make it a
 little faster.
 But then we will have to take into account the difference
 between apr_time_t's
 and seconds. :-(

 Greg

 
  {72114} poll(0x6fd88910, 1, 12) .. = 1
  {72114} read(149, G E T   / ? / f i l e _ s e t / .., 8000) =
159
  {72114} gettimeofday(0x6fd88448, NULL) ... = 0
  {72114} time(NULL) ... =
 1043344112
  {72114} time(NULL) ... =
 1043344112
  {72114} time(NULL) ... =
 1043344112
  {72114}
 stat(/opt/apache2/htdocs//file_set/dir00016/class1_8, 0x6fd885c8)
  = 0
  {72114}
 open(/opt/apache2/htdocs//file_set/dir00016/class1_8, O_RDONLY,
  0666)
  = 43
  {72114} read(43,   9 2 1 6   f i l e _ s .., 9216) =
9216
  {72114} writev(149, 0x6fd88988, 4) ... = 9803
  {72114} read(149, 0x40288078, 8000) ..
 ERR#11 EAGAIN
  {72114} write(8, 1 9 2 . 1 6 8 . 3 . 2   [ 2 3 / .., 95) = 95
  {72114} close(43)  = 0
  {72114} poll(0x6fd88910, 1, 12) .. = 1
  {72114} read(149, G E T   / f i l e _ s e t / d i .., 8000) = 70
  {72114} gettimeofday(0x6fd88448, NULL) ... = 0
  {72114}
 stat(/opt/apache2/htdocs/file_set/dir00047/class1_0, 0x6fd88548) =
  0
  {72114}
 open(/opt/apache2/htdocs/file_set/dir00047/class1_0, O_RDONLY, 0)
  = 55
  {72114} read(149, 0x40288078, 8000) ..
 ERR#11 EAGAIN
  {72114} sendfile(149, 55, 0, 1024, 0x6fd88688, 0)  = 1289
  {72114} write(8, 1 9 2 . 1 6 8 . 3 . 2   [ 2 3 / .., 93) = 93
  {72114} poll(0x6fd88910, 1, 12) .. = 1
  {72114} read(149, G E T   / f i l e _ s e t / d i .., 8000) = 70
  {72114} gettimeofday(0x6fd88448, NULL) ... = 0
  {72114}
 stat(/opt/apache2/htdocs/file_set/dir9/class0_3, 0x6fd88548) =
  0
  {72114}
 open(/opt/apache2/htdocs/file_set/dir9/class0_3, O_RDONLY, 0)
  = 59
  {72114} read(149, 0x4038c098, 8000) ..
 ERR#11 EAGAIN
  {72114} sendfile(149, 59, 0, 409, 0x6fd88688, 0) . = 673
  {72114} write(8, 1 9 2 . 1 6 8 . 3 . 2   [ 2 3 / .., 92) = 92
  {72114} poll(0x6fd88910, 1, 12) .. = 1
  {72114} read(149, G E T   / f i l e _ s e t / d i .., 8000) = 70
  {72114} gettimeofday(0x6fd88448, NULL) ... = 0
  {72114}
 stat(/opt/apache2/htdocs/file_set/dir0/class1_2, 0x6fd88548) =
  0
  {72114}
 open(/opt/apache2/htdocs/file_set/dir0/class1_2, O_RDONLY, 0)
  = 76
  {72114} read(149, 0x40288078, 8000) ..
 ERR#11 EAGAIN
  {72114} sendfile(149, 76, 0, 3072, 0x6fd88688, 0)  = 3336
  {72114} write(8, 1 9 2 . 1 6 8 . 3 . 2   [ 2 3 / .., 93) = 93
 

RE: gettimeofday calls

[MATHIHALLI,MADHUSUDAN (HP-Cupertino,ex1)]

I tried that, and I got back error from specweb99 stating that the responses
were not conforming. (or something like that).. 

Now, I have a global time variable, that I set once in
specweb99_quick_handler(), and the other two instances, try to use it,
rather than compute again.. The third time() - in the ap_log_error(), I've
put it in ifdef DEBUG :-).. Trying this out now..

-Madhu

-Original Message-
From: David Hill [mailto:[EMAIL PROTECTED]
Sent: Thursday, January 23, 2003 1:56 PM
To: [EMAIL PROTECTED]
Subject: Re: gettimeofday calls




I would think that using the http request time would meet the spec and
be easier than your alternatives...

Dave
- Original Message -
From: MATHIHALLI,MADHUSUDAN (HP-Cupertino,ex1)
[EMAIL PROTECTED]
To: [EMAIL PROTECTED]
Sent: Thursday, January 23, 2003 4:05 PM
Subject: RE: gettimeofday calls


 I don't know if this has been discussed already, but I was thinking
of the
 following alternatives :
 1. how about the listener thread in each of the child process keeps
updating
 a global time variable that each of the threads can refer to ?.
 2. set the time at the begining of the process, and then each of the
thread
 measures the amount of time it has been running.. (Current time =
startup
 time + delta time).. AFAIK, the time taken to compute delta time is
much
 lesser than gettimeofday..

 Is this against the spec or something ?.

 -Madhu

 -Original Message-
 From: Greg Ames [mailto:[EMAIL PROTECTED]
 Sent: Thursday, January 23, 2003 11:19 AM
 To: [EMAIL PROTECTED]
 Subject: Re: gettimeofday calls


 MATHIHALLI,MADHUSUDAN (HP-Cupertino,ex1) wrote:

  The following is the tusc output of httpd (2.0.43) +
 mod_specweb99.c
  on HP-UX.. Almost every single request has a gettimeofday
 system call - is
  there any way to avoid it ?.

 The GET /file_set/* requests are just plain ol' static files
 served by the httpd
 core, so I think the gettimeofday is due to:

  r-request_time = apr_time_now();

 ...line 681 from server/protocol.c.  I don't see that going
 away in the near future.

 OTOH, the GET /?/file_set/* is a dynamic request served by
 mod_specweb99.  The
 three time() syscalls there bother me.  I'm guessing that this
 request had a
 cookie which drives do_cadget() and friends.  Looking at code
 in that path I do
 see three different time calls.  One of them will go away if
 you select a
 quieter LogLevel...you probably have Found ad blah expire
yes/no
 timestamp messages in your error log.

 Off the top of my head, we could probably change mod_specweb99 to
use
 r-request_time in place of the time() syscalls and make it a
 little faster.
 But then we will have to take into account the difference
 between apr_time_t's
 and seconds. :-(

 Greg

 
  {72114} poll(0x6fd88910, 1, 12) .. = 1
  {72114} read(149, G E T   / ? / f i l e _ s e t / .., 8000) =
159
  {72114} gettimeofday(0x6fd88448, NULL) ... = 0
  {72114} time(NULL) ... =
 1043344112
  {72114} time(NULL) ... =
 1043344112
  {72114} time(NULL) ... =
 1043344112
  {72114}
 stat(/opt/apache2/htdocs//file_set/dir00016/class1_8, 0x6fd885c8)
  = 0
  {72114}
 open(/opt/apache2/htdocs//file_set/dir00016/class1_8, O_RDONLY,
  0666)
  = 43
  {72114} read(43,   9 2 1 6   f i l e _ s .., 9216) =
9216
  {72114} writev(149, 0x6fd88988, 4) ... = 9803
  {72114} read(149, 0x40288078, 8000) ..
 ERR#11 EAGAIN
  {72114} write(8, 1 9 2 . 1 6 8 . 3 . 2   [ 2 3 / .., 95) = 95
  {72114} close(43)  = 0
  {72114} poll(0x6fd88910, 1, 12) .. = 1
  {72114} read(149, G E T   / f i l e _ s e t / d i .., 8000) = 70
  {72114} gettimeofday(0x6fd88448, NULL) ... = 0
  {72114}
 stat(/opt/apache2/htdocs/file_set/dir00047/class1_0, 0x6fd88548) =
  0
  {72114}
 open(/opt/apache2/htdocs/file_set/dir00047/class1_0, O_RDONLY, 0)
  = 55
  {72114} read(149, 0x40288078, 8000) ..
 ERR#11 EAGAIN
  {72114} sendfile(149, 55, 0, 1024, 0x6fd88688, 0)  = 1289
  {72114} write(8, 1 9 2 . 1 6 8 . 3 . 2   [ 2 3 / .., 93) = 93
  {72114} poll(0x6fd88910, 1, 12) .. = 1
  {72114} read(149, G E T   / f i l e _ s e t / d i .., 8000) = 70
  {72114} gettimeofday(0x6fd88448, NULL) ... = 0
  {72114}
 stat(/opt/apache2/htdocs/file_set/dir9/class0_3, 0x6fd88548) =
  0
  {72114}
 open(/opt/apache2/htdocs/file_set/dir9/class0_3, O_RDONLY, 0)
  = 59
  {72114} read(149, 0x4038c098, 8000) ..
 ERR#11 EAGAIN
  {72114} sendfile(149, 59, 0, 409, 0x6fd88688, 0) . = 673
  {72114} write(8, 1 9 2 . 1 6 8 . 3 . 2   [ 2 3 / .., 92) = 92
  {72114} poll(0x6fd88910, 1, 12) .. = 1
  {72114} read(149, G E T   / f i l e _ s e t / d i .., 8000) = 70
  {72114} gettimeofday