精确得到apache每个页面运行时间，以便优化程序性能

linux_prog

from: http://www.loveopensource.com/?p=34
by linux_prog
Apache提供的logFormat选项中对页面执行时间%T只能精确到秒。
写了个模块，能够精确到毫秒，利用这个模块可以很方便的进行系统的性能诊断，找出有瓶颈的程序，进行优化，有需要的话可以参考。
/*
mod_responseCost for apache2.
Author:Seamus
To compute a HTTP request cost time.
Install:
./bin/apxs -c ./mod_responseCost.c
./bin/apxs -a -i -n responseCost ./mod_responseCost.la

add to logFormat:
\”%{responseCost}n\”
*/

#include  <time.h>
#include <stdlib.h>
#include “apr.h”
#include “apr_lib.h”
#include “apr_strings.h”

#define APR_WANT_STRFUNC
#include “apr_want.h”
#include “httpd.h”
#include “http_config.h”
#include “http_core.h”
#include “http_request.h”
#include “ap_mpm.h”

typedef long long n64_t;
#define NOTE_NAME “responseCost”

n64_t *time_array;
module AP_MODULE_DECLARE_DATA responseCost_module;

static apr_status_t responseCost_cleanup(void *not_used)
{
fprintf(stderr, “pid:%d, exiting…\n”, getpid());
free(time_array);
return OK;
}

static void responseCostInit(apr_pool_t *p, server_rec *s)
{
fprintf(stderr, “pid:%d starting…”, getpid());
    int is_threaded = 0, hard_thread_limit = 0, max_threads = 0;  
    ap_mpm_query(AP_MPMQ_IS_THREADED, &is_threaded);
    if (is_threaded)
    {
        ap_mpm_query(AP_MPMQ_HARD_LIMIT_THREADS, &hard_thread_limit);
        ap_mpm_query(AP_MPMQ_MAX_THREADS, &max_threads);
        max_threads = max_threads < hard_thread_limit ? max_threads : hard_thread_limit;
    }
    else
    {
        max_threads = 1;
    }
time_array = (n64_t *)malloc(sizeof(n64_t)*max_threads);
    apr_pool_cleanup_register(p, (void *)&max_threads, responseCost_cleanup, apr_pool_cleanup_null);
}

static int compute_time(request_rec *r)
{
    int is_threaded = 0, hard_thread_limit = 0, max_threads = 0;  
    ap_mpm_query(AP_MPMQ_IS_THREADED, &is_threaded);
    if (is_threaded)
    {
        ap_mpm_query(AP_MPMQ_HARD_LIMIT_THREADS, &hard_thread_limit);
        ap_mpm_query(AP_MPMQ_MAX_THREADS, &max_threads);
        max_threads = max_threads < hard_thread_limit ? max_threads : hard_thread_limit;
    }
    else
    {
        max_threads = 1;
    }  
    struct timeval t;
gettimeofday(&t, NULL);
    n64_t now_time  = t.tv_sec * 1000000LL + t.tv_usec;
    n64_t cost_time = now_time - time_array[r->connection->id % hard_thread_limit];
    char timechar[256];
    snprintf(timechar, sizeof(timechar), “cost %lld ms”, cost_time/1000);
    apr_table_setn(r->notes, NOTE_NAME, apr_pstrdup(r->pool, timechar));
    return OK;
}

static int record_time(request_rec *r)
{
    int is_threaded = 0, hard_thread_limit = 0, max_threads = 0;  
    ap_mpm_query(AP_MPMQ_IS_THREADED, &is_threaded);
    if (is_threaded)
    {
        ap_mpm_query(AP_MPMQ_HARD_LIMIT_THREADS, &hard_thread_limit);
        ap_mpm_query(AP_MPMQ_MAX_THREADS, &max_threads);
        max_threads = max_threads < hard_thread_limit ? max_threads : hard_thread_limit;
    }
    else
    {
        max_threads = 1;
    }  
    struct timeval t;
gettimeofday(&t, NULL);
    time_array[r->connection->id % hard_thread_limit] = t.tv_sec * 1000000LL + t.tv_usec;
    return OK;
}

static void register_hooks(apr_pool_t *p)
{
    /* init global array */
    ap_hook_child_init(responseCostInit, NULL, NULL, APR_HOOK_MIDDLE);
    /* record begin time */
ap_hook_fixups(record_time, NULL, NULL, APR_HOOK_MIDDLE);
/* set response time */
ap_hook_log_transaction(compute_time, NULL, NULL, APR_HOOK_FIRST);
return;
}

/* module structure */
module AP_MODULE_DECLARE_DATA responseCost_module = {
    STANDARD20_MODULE_STUFF,
    NULL,                        /* dir config creater                    */
    NULL,                        /* dir merger — default is to override */
    NULL,                /* server config                         */
    NULL,                        /* merge server configs                  */
    NULL,                   /* command apr_table_t                   */
    register_hooks           /* register hooks                        */
};