apr-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Brian Pane <bp...@pacbell.net>
Subject Re: profile...
Date Wed, 01 Aug 2001 04:19:47 GMT
David Reid wrote:

>What follows is a profile for beos bone running 1000 connections using 
>a single thread (-DONE_PROCESS).  Columns are
>
>no. of calls
>time in calls
>time incl sub calls
>function name
>
>Raises some interesting questions, like how many times do we call 
>ap_palloc/ap_pcalloc/lock/unlock and stat for 1000 requests?  I've 
>chopped some of the lower order ones off the end to try and stop it 
>being too huge.
>
>It'd be interesting to know where the ap_pallocs & ap_pcalloc are as it 
>looks like we're using a good few pre request...
>
The following data might be useful.  It's a fragment of a gprof function
call profile showing the major callers of apr_palloc/apr_pcalloc.  In the
test case that produced this profile, I sent the httpd 500,000 requests
for a server-parsed file that included 5 other server-parsed files.

The biggest customers of apr_palloc include ap_merge_per_dir_configs
(from directory_walk), bucket brigades (apr_brigade_create plus
apr_pool_cleanup_register for the registration of bucket cleanups),
subrequest creation (in particular the creation of tables in the
sub-request_rec), and lots of apr_pstrcat and apr_pstrdup operations.

The brigade overhead in particular might explain a lot of the slowness
of mod_include in 2.0, relative to 1.3.  Does anybody have ideas on
how to optimize this?
For clarity, I've omitted all callers that did less than one
apr_palloc or apr_palloc call per request:

                                #of calls            function
                              ----------------     -------------------------
                0.00    0.00  500000/231005645     basic_http_header [111]
                0.00    0.00  500000/231005645     apr_itoa [138]
                0.00    0.00  500000/231005645     apr_parse_addr_port [139]
                0.00    0.00 1000000/231005645     ap_getword_white [127]
                0.00    0.00 1000000/231005645     apr_sockaddr_ip_get [128]
                0.00    0.00 1500000/231005645     
config_log_transaction [102]
                0.00    0.00 1500000/231005645     get_mime_headers [85]
                0.00    0.00 2500000/231005645     apr_table_copy [78]
                0.00    0.00 3000000/231005645     ap_make_method_list [67]
                0.00    0.00 3000000/231005645     analyze_ct [61]
                0.00    0.00 3000000/231005645     find_ct [51]
                0.00    0.00 3000000/231005645     ap_set_last_modified [92]
                0.00    0.00 3000000/231005645     directory_walk [39]
                0.00    0.00 3500000/231005645     apr_off_t_toa [88]
                0.00    0.00 3500233/231005645     apr_array_make [70]
                0.00    0.00 4500000/231005645     mmap_setaside [66]
                0.00    0.00 9000000/231005645     
ap_merge_per_dir_configs [37]
                0.00    0.00 9000000/231005645     
merge_core_dir_configs [40]
                0.00    0.00 9500050/231005645     apr_pstrndup [64]
                0.00    0.00 11500020/231005645     apr_table_make [46]
                0.00    0.00 12500233/231005645     apr_pstrcat [60]
                0.00    0.00 19000000/231005645     apr_brigade_create [41]
                0.00    0.00 19500969/231005645     apr_pstrdup [49]
                0.00    0.00 27000000/231005645     apr_array_copy_hdr [45]
                0.00    0.00 30000070/231005645     
apr_pool_cleanup_register [43]
                0.00    0.00 48501583/231005645     apr_pcalloc [36]
[23]    10.3    0.00    0.00 231005645         apr_palloc [23]

The numbers in the column just before the function names mean
that, for example, apr_pcalloc made 48,501,583 of the 231,005,645
calls to apr_palloc in the test.

The top callers of apr_pcalloc were:

                                #of calls            function
                              ----------------     -------------------------
                0.00    0.00  500000/48501583     ap_http_filter <cycle 
3> [118]
                0.00    0.00  500000/48501583     ap_new_connection [99]
                0.00    0.00  500000/48501583     ap_read_request [38]
                0.00    0.00  500000/48501583     
ap_content_length_filter <cycle 1> [58]
                0.00    0.00  500000/48501583     core_output_filter [108]
                0.00    0.00  500000/48501583     core_create_req [116]
                0.00    0.00 1500006/48501583     alloc_socket [112]
                0.00    0.00 2500000/48501583     make_sub_request [30]
                0.00    0.00 3000000/48501583     includes_filter <cycle 
1> [55]
                0.00    0.00 3000000/48501583     apr_array_cat [94]
                0.00    0.00 3000000/48501583     apr_mmap_create [73]
                0.00    0.00 3000008/48501583     apr_file_open [65]
                0.00    0.00 3500014/48501583     create_empty_config [87]
                0.00    0.00 8500000/48501583     add_any_filter [68]
                0.00    0.00 17500253/48501583     make_array_core [52]
[36]     2.2    0.00    0.00 48501583         apr_pcalloc [36]
                0.00    0.00 48501583/231005645     apr_palloc [23]



Mime
View raw message