- publishing free software manuals
The Apache HTTP Server Reference Manual
by Apache Software Foundation
Paperback (6"x9"), 862 pages
ISBN 9781906966034
RRP £19.95 ($29.95)

Get a printed copy>>>

23.4  Appendix: Detailed Analysis of a Trace

Here is a system call trace of Apache 2.0.38 with the worker MPM on Solaris 8. This trace was collected using:

truss -l -p httpd_child_pid.

The -l option tells truss to log the ID of the LWP (lightweight process–Solaris’s form of kernel-level thread) that invokes each system call.

Other systems may have different system call tracing utilities such as strace, ktrace, or par. They all produce similar output.

In this trace, a client has requested a 10KB static file from the httpd. Traces of non-static requests or requests with content negotiation look wildly different (and quite ugly in some cases).

/67:    accept(3, 0x00200BEC, 0x00200C0C, 1) (sleeping...)  
/67:    accept(3, 0x00200BEC, 0x00200C0C, 1) = 9

In this trace, the listener thread is running within LWP #67.

Note the lack of accept(2) serialization. On this particular platform, the worker MPM uses an unserialized accept by default unless it is listening on multiple ports.

/65:    lwp_park(0x00000000, 0) = 0  
/67:    lwp_unpark(65, 1) = 0

Upon accepting the connection, the listener thread wakes up a worker thread to do the request processing. In this trace, the worker thread that handles the request is mapped to LWP #65.

/65:    getsockname(9, 0x00200BA4, 0x00200BC4, 1) = 0

In order to implement virtual hosts, Apache needs to know the local socket address used to accept the connection. It is possible to eliminate this call in many situations (such as when there are no virtual hosts, or when Listen directives are used which do not have wildcard addresses). But no effort has yet been made to do these optimizations.

/65:    brk(0x002170E8) = 0  
/65:    brk(0x002190E8) = 0

The brk(2) calls allocate memory from the heap. It is rare to see these in a system call trace, because the httpd uses custom memory allocators (apr_pool and apr_bucket_alloc) for most request processing. In this trace, the httpd has just been started, so it must call malloc(3) to get the blocks of raw memory with which to create the custom memory allocators.

/65:    fcntl(9, F_GETFL, 0x00000000) = 2  
/65:    fstat64(9, 0xFAF7B818) = 0  
/65:    getsockopt(9, 65535, 8192, 0xFAF7B918,  
                   0xFAF7B910, 2190656) = 0  
/65:    fstat64(9, 0xFAF7B818) = 0  
/65:    getsockopt(9, 65535, 8192, 0xFAF7B918,  
                   0xFAF7B914, 2190656) = 0  
/65:    setsockopt(9, 65535, 8192, 0xFAF7B918,  
                   4, 2190656) = 0  
/65:    fcntl(9, F_SETFL, 0x00000082) = 0

Next, the worker thread puts the connection to the client (file descriptor 9) in non-blocking mode. The setsockopt(2) and getsockopt(2) calls are a side-effect of how Solaris’s libc handles fcntl(2) on sockets.

/65:    read(9, " G E T   / 1 0 k . h t m".., 8000) = 97

The worker thread reads the request from the client.

/65:    stat("/var/httpd/apache/httpd-8999/htdocs/10k.html",  
             0xFAF7B978) = 0  
/65:    open("/var/httpd/apache/httpd-8999/htdocs/10k.html",  
             O_RDONLY) = 10

This httpd has been configured with Options FollowSymLinks and AllowOverride None. Thus it doesn’t need to lstat(2) each directory in the path leading up to the requested file, nor check for .htaccess files. It simply calls stat(2) to verify that the file: 1) exists, and 2) is a regular file, not a directory.

/65:    sendfilev(0, 9, 0x00200F90, 2, 0xFAF7B53C) = 10269

In this example, the httpd is able to send the HTTP response header and the requested file with a single sendfilev(2) system call. Sendfile semantics vary among operating systems. On some other systems, it is necessary to do a write(2) or writev(2) call to send the headers before calling sendfile(2).

/65:    write(4, " 1 2 7 . 0 . 0 . 1   -  ".., 78) = 78

This write(2) call records the request in the access log. Note that one thing missing from this trace is a time(2) call. Unlike Apache 1.3, Apache 2.x uses gettimeofday(3) to look up the time. On some operating systems, like Linux or Solaris, gettimeofday has an optimized implementation that doesn’t require as much overhead as a typical system call.

/65:    shutdown(9, 1, 1) = 0  
/65:    poll(0xFAF7B980, 1, 2000) = 1  
/65:    read(9, 0xFAF7BC20, 512) = 0  
/65:    close(9) = 0

The worker thread does a lingering close of the connection.

/65:    close(10) = 0  
/65:    lwp_park(0x00000000, 0) (sleeping...)

Finally the worker thread closes the file that it has just delivered and blocks until the listener assigns it another connection.

/67:    accept(3, 0x001FEB74, 0x001FEB94, 1) (sleeping...)

Meanwhile, the listener thread is able to accept another connection as soon as it has dispatched this connection to a worker thread (subject to some flow-control logic in the worker MPM that throttles the listener if all the available workers are busy). Though it isn’t apparent from this trace, the next accept(2) can (and usually does, under high load conditions) occur in parallel with the worker thread’s handling of the just-accepted connection.

ISBN 9781906966034The Apache HTTP Server Reference ManualSee the print edition