You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@httpd.apache.org by Bill Stoddard <bi...@wstoddard.com> on 2002/07/03 06:09:05 UTC
Apache 2 cycle vs instruction profiling (2.0.40-dev)
Here is a profile of 2.0.40-dev HEAD as of an hour or so ago. It is an
improvement over the earlier runs. Instruction count dropped from 58115 to
54888. Part of that was eliminating the duplicate ap_set_keepalive() call.
Bill
Space % Cycles
===== ==== =====
User 18.4 44458
Shared Library 47.9 115610
Kernel 33.7 81465
Total 241533 (4.40 per instruction)
/usr/local/apachetest/bin/httpd :
Subroutine Name Source File Ratio Enter %
Cycles
=============== =========== ===== ===== ====
======
.core_input_filter core.c 3.05 11 1.5 3515
.ap_rgetline_core protocol.c 3.32 6 1.4 3428
.get_filter_handle util_filter.c 4.62 2 1.1 2730
.add_any_filter_handle util_filter.c 4.55 6 0.9 2173
._ptrgl ptrgl.s 4.94 66 0.8 1956
.net_time_filter core.c 3.16 12 0.8 1865
.fix_hostname vhost.c 3.61 1 0.7 1611
.core_output_filter core.c 3.56 2 0.6 1440
.add_any_filter util_filter.c 4.97 1 0.5 1277
.ap_update_child_status_from_indexes scoreboard.c 15.75 2 0.5 1260
.ap_get_brigade util_filter.c 3.50 25 0.5 1137
._moveeq moveeq.s 4.98 14 0.4 1080
.ap_find_token util.c 4.45 3 0.4 1019
.ap_read_request protocol.c 6.35 1 0.3 839
.ap_get_mime_headers protocol.c 3.51 1 0.3 800
.ap_content_length_filter protocol.c 5.03 1 0.3 794
.ap_getword_white util.c 2.83 2 0.3 719
.ap_pass_brigade util_filter.c 5.30 5 0.3 642
.ap_set_keepalive http_protocol.c 3.77 1 0.2 558
.read_request_line protocol.c 4.48 1 0.2 542
.apr_palloc glink.s 3.82 22 0.2 504
.log_error_core log.c 3.99 4 0.2 479
.ap_recent_rfc822_date util_time.c 2.47 1 0.2 470
.ap_run_quick_handler config.c 16.55 1 0.2 464
.isspace glink.s 2.88 22 0.2 380
.ap_http_filter http_protocol.c 3.74 2 0.2 371
.lookup_builtin_method http_protocol.c 13.62 1 0.2 368
.tolower glink.s 2.90 19 0.1 331
.ap_process_http_connection http_core.c 9.24 0 0.1 323
.core_create_req core.c 5.49 1 0.1 318
.apr_brigade_destroy glink.s 6.62 8 0.1 318
.isalpha glink.s 2.77 19 0.1 316
.ap_run_create_request request.c 6.82 1 0.1 307
.apr_brigade_split_line glink.s 8.47 6 0.1 305
.ap_log_error log.c 3.32 4 0.1 292
.ap_add_output_filters_by_type core.c 12.68 1 0.1 292
.ap_run_log_transaction protocol.c 8.74 1 0.1 288
.writev_it_all core.c 6.38 1 0.1 287
.ap_run_post_read_request protocol.c 7.97 1 0.1 271
.http_create_request http_core.c 7.09 1 0.1 270
.apr_setsocketopt glink.s 3.82 11 0.1 252
.basic_http_header http_protocol.c 2.98 1 0.1 250
.ap_process_request http_request.c 9.14 1 0.1 247
.apr_table_get glink.s 3.23 12 0.1 232
.cached_explode util_time.c 3.55 1 0.1 230
.avoid_xlc_bug core.c 5.16 11 0.1 227
.apr_brigade_create glink.s 3.41 11 0.1 225
.apr_table_make glink.s 6.19 6 0.1 223
.create_empty_config config.c 10.49 1 0.1 220
.check_pipeline_flush http_request.c 4.89 1 0.1 215
.ap_discard_request_body http_protocol.c 3.03 1 0.1 215
.strlen glink.s 8.45 4 0.1 203
.ap_update_vhost_from_headers vhost.c 6.34 1 0.1 196
.basic_http_header_check http_protocol.c 4.68 1 0.1 196
.__divi64 glink.s 10.19 3 0.1 184
.form_header_field http_protocol.c 2.33 2 0.1 182
.ap_update_child_status scoreboard.c 12.27 2 0.1 172
.isdigit glink.s 14.00 2 0.1 168
.apr_brigade_cleanup glink.s 5.58 5 0.1 167
.ap_parse_uri protocol.c 3.78 1 0.1 166
.apr_sendv glink.s 27.54 1 0.1 165
.apr_brigade_puts glink.s 6.88 4 0.1 165
.apr_brigade_write glink.s 3.13 8 0.1 150
.apr_pstrcatv glink.s 24.75 1 0.1 148
.ap_byterange_filter http_protocol.c 4.59 1 0.1 133
.ap_add_output_filter util_filter.c 16.66 1 0.1 133
.apr_pool_destroy glink.s 21.67 1 0.1 130
.apr_pstrdup glink.s 20.67 1 0.1 124
.ap_graceful_stop_signalled worker.c 41.17 1 0.1 124
.apr_off_t_toa glink.s 20.33 1 0.1 122
.apr_uri_parse glink.s 19.88 1 0.0 119
.ap_basic_http_header http_protocol.c 7.87 1 0.0 118
.ap_set_content_length protocol.c 5.85 1 0.0 117
.strchr glink.s 4.69 4 0.0 112
.remove_any_filter util_filter.c 3.47 2 0.0 108
.ap_make_method_list http_protocol.c 4.14 1 0.0 104
.ap_set_byterange http_protocol.c 3.22 1 0.0 103
.ap_get_server_version core.c 19.25 1 0.0 96
.apr_array_make glink.s 15.96 1 0.0 96
.ap_remove_output_filter util_filter.c 4.72 2 0.0 94
.memset glink.s 3.90 4 0.0 94
.ap_set_content_type http_protocol.c 4.18 1 0.0 88
.apr_table_mergen glink.s 14.62 1 0.0 88
.apr_table_overlap glink.s 14.42 1 0.0 86
.apr_table_addn glink.s 3.49 4 0.0 84
.apr_parse_addr_port glink.s 13.08 1 0.0 78
.ap_get_output_filter_handle util_filter.c 12.83 2 0.0 77
.apr_brigade_partition glink.s 3.16 4 0.0 76
.ap_index_of_response http_protocol.c 3.87 1 0.0 74
.ap_get_limit_req_body core.c 10.39 1 0.0 73
.apr_brigade_split glink.s 2.35 5 0.0 70
.apr_time_now glink.s 10.79 1 0.0 65
.apr_pool_create_ex glink.s 10.08 1 0.0 60
.apr_bucket_flush_create glink.s 9.50 1 0.0 57
.strncasecmp glink.s 4.60 2 0.0 55
.ap_add_output_filter_handle util_filter.c 3.00 3 0.0 54
.ap_method_number_of http_protocol.c 2.40 1 0.0 48
.ap_finalize_request_protocol protocol.c 2.42 1 0.0 46
.ap_create_request_config config.c 38.75 1 0.0 39
.apr_pstrmemdup glink.s 5.75 1 0.0 34
.ap_add_input_filter_handle util_filter.c 2.83 2 0.0 34
.apr_psprintf glink.s 5.58 1 0.0 34
.apr_table_setn glink.s 2.17 2 0.0 26
.apr_table_unset glink.s 2.17 2 0.0 26
.apr_bucket_eos_create glink.s 2.17 1 0.0 13
.ap_explode_recent_gmt util_time.c 2.75 1 0.0 11
Shlib Subroutine Source File Ratio Enter %
Cycles
================ =========== ===== ===== ====
======
.memset memset.s 5.63 9 6.3 15311
.__is_wctype_std libc/__is_wctype_std.c 3.41 66 1.9 4498
.apr_table_get apr_tables.c 3.26 17 1.8 4255
.apr_palloc apr_pools.c 2.13 95 1.5 3641
._moveeq moveeq.s 4.47 11 1.4 3283
.__divu64 divu64.s 2.72 3 1.1 2675
.memchr libc/memchr.c 3.61 11 1.1 2667
.apr_table_setn apr_tables.c 3.04 12 1.1 2633
.apr_setsocketopt sockopt.c 3.34 13 1.1 2599
.strcasecmp libaixinet/strcasecmp.c 3.70 7 1.0 2519
.__divi64 divi64.s 2.78 4 1.0 2308
.strlen strlen.s 3.39 14 0.8 1877
.apr_brigade_cleanup apr_brigade.c 3.05 17 0.8 1839
.apr_vformatter apr_snprintf.c 4.32 1 0.8 1824
.pthread_mutex_lock libpthreads/mutex.c 10.02 3 0.7 1774
.apr_bucket_alloc apr_buckets_alloc.c 2.55 28 0.7 1580
.apr_brigade_puts apr_brigade.c 2.31 5 0.7 1578
.apr_brigade_split_line apr_brigade.c 2.81 6 0.6 1498
.isspace libc/isspace.c 3.08 23 0.6 1418
.apr_brigade_write apr_brigade.c 2.13 11 0.5 1198
.cache_url_handler mod_cache.c 5.79 1 0.5 1130
.multi_log_transaction mod_log_config.c 36.36 1 0.5 1127
.allocator_alloc apr_pools.c 4.35 5 0.5 1120
._ptrgl ptrgl.s 2.78 63 0.4 1050
.apr_brigade_create apr_brigade.c 2.23 17 0.4 1023
._ptrgl ptrgl.s 2.42 70 0.4 1018
.apr_bucket_simple_copy apr_buckets_simple.c 3.72 14 0.4 990
.apr_bucket_free apr_buckets_alloc.c 2.56 28 0.4 963
.allocator_free apr_pools.c 4.19 5 0.4 953
.apr_pool_cleanup_register apr_pools.c 2.22 18 0.4 920
._moveeq moveeq.s 4.04 13 0.4 864
.tolower libc/tolower.c 2.64 19 0.4 851
.apr_array_push_noclear apr_tables.c 1.78 20 0.3 814
.make_array_core apr_tables.c 2.40 12 0.3 792
.strchr strchr.s 2.90 5 0.3 778
.isalpha libc/isalpha.c 1.94 19 0.3 738
.apr_bucket_simple_split apr_buckets_simple.c 2.30 10 0.3 713
.apr_table_overlap apr_tables.c 3.42 1 0.3 700
.match_headers mod_setenvif.c 18.42 1 0.3 700
.heap_bucket_destroy apr_buckets_heap.c 2.68 17 0.3 694
.strncasecmp libaixinet/strcasecmp.c 3.20 3 0.3 692
.find_entry cache_hash.c 4.74 1 0.3 663
.apr_palloc glink.s 3.05 36 0.3 658
.isupper libc/isupper.c 1.71 19 0.3 648
.run_cleanups apr_pools.c 12.68 1 0.3 609
.apr_uri_parse apr_uri.c 4.97 1 0.2 596
.overlap_hash apr_tables.c 3.53 4 0.2 592
.apr_pool_cleanup_kill apr_pools.c 4.36 8 0.2 585
.unserialize_table mod_mem_cache.c 3.83 4 0.2 578
.pthread_mutex_unlock libpthreads/mutex.c 4.80 3 0.2 576
.apr_table_unset apr_tables.c 2.71 2 0.2 561
.apr_brigade_destroy apr_brigade.c 4.12 8 0.2 561
.apr_bucket_alloc glink.s 3.28 28 0.2 550
.read libc/read.c 7.40 2 0.2 518
.heap_bucket_read apr_buckets_heap.c 1.89 30 0.2 511
.spin_lock_global_ppc_up locks_ppc_up.s 15.15 3 0.2 500
.apr_recv sendrecv.c 4.76 2 0.2 495
.apr_brigade_partition apr_brigade.c 3.43 4 0.2 493
.cache_out_filter mod_cache.c 5.68 1 0.2 489
.apr_table_make apr_tables.c 2.48 10 0.2 471
.socket_bucket_read apr_buckets_socket.c 3.96 2 0.2 468
.apr_pool_cleanup_kill glink.s 9.61 8 0.2 462
.apr_pvsprintf apr_pools.c 9.31 1 0.2 456
.apr_bucket_shared_destroy glink.s 4.32 17 0.2 441
.ap_cache_get_cachetype cache_util.c 7.66 1 0.2 436
.apr_atomic_dec apr_atomic.c 14.07 1 0.2 436
.open_entity mod_mem_cache.c 5.16 1 0.2 418
.cache_select_url cache_storage.c 5.77 1 0.2 416
.pthread_mutex_lock glink.s 22.47 3 0.2 404
.apr_palloc glink.s 3.92 17 0.2 400
.pthread_mutex_unlock glink.s 22.17 3 0.2 399
.apr_bucket_shared_split apr_buckets_refcount.c 2.18 10 0.2 392
.apr_table_mergen apr_tables.c 3.99 1 0.2 372
.kread glink.s 30.69 2 0.2 368
.apr_sendv sendrecv.c 7.98 1 0.2 367
.apr_atomic_inc apr_atomic.c 12.03 1 0.1 349
.apr_bucket_heap_make apr_buckets_heap.c 3.60 3 0.1 346
.apr_thread_mutex_lock thread_mutex.c 7.20 3 0.1 346
.apr_table_addn apr_tables.c 2.20 4 0.1 343
.cache_run_open_entity cache_storage.c 10.55 1 0.1 338
.apr_wait_for_io_or_timeout sendrecv.c 5.97 1 0.1 328
.strcasecmp glink.s 8.81 6 0.1 317
.apr_pool_cleanup_register glink.s 3.08 17 0.1 314
.apr_bucket_shared_destroy apr_buckets_refcount.c 3.08 17 0.1 314
.apr_brigade_split apr_brigade.c 2.26 5 0.1 312
.apr_bucket_simple_split glink.s 5.19 10 0.1 312
.apr_pool_destroy apr_pools.c 5.84 1 0.1 310
.islower libc/islower.c 7.59 2 0.1 304
.apr_pstrdup apr_strings.c 2.61 5 0.1 303
.spin_unlock_global_ppc_up locks_ppc_up.s 7.26 3 0.1 283
._ptrgl ptrgl.s 11.62 4 0.1 279
.apr_parse_addr_port sockaddr.c 4.54 1 0.1 277
.__pthread_geterrno_addr libpthreads/lib_lock.c 5.58 4 0.1 268
.read_headers mod_mem_cache.c 3.99 1 0.1 255
.apr_bucket_shared_make glink.s 14.07 3 0.1 253
._Errno libc/errno.c 4.39 3 0.1 250
.writev libc/write.c 12.21 1 0.1 244
.isdigit libc/isdigit.c 4.07 3 0.1 244
.read_real_time read_real_time.s 8.66 1 0.1 242
.apr_pstrcatv apr_strings.c 2.88 1 0.1 242
.apr_allocator_alloc glink.s 9.93 4 0.1 238
.apr_pool_create_ex apr_pools.c 3.56 1 0.1 238
.apr_vformatter glink.s 36.12 1 0.1 217
.islower glink.s 18.00 2 0.1 216
.gettimeofday libc/gettimeofday.c 5.07 1 0.1 213
.conv_10 apr_snprintf.c 3.03 2 0.1 212
.apr_recv glink.s 17.04 2 0.1 204
.strlen glink.s 6.72 5 0.1 202
.read_body mod_mem_cache.c 4.70 1 0.1 197
.read glink.s 16.29 2 0.1 196
._ptrgl ptrgl.s 8.14 4 0.1 195
.writev glink.s 30.79 1 0.1 185
.bzero glink.s 30.58 1 0.1 184
.memchr glink.s 3.05 10 0.1 183
.apr_off_t_toa apr_strings.c 2.77 1 0.1 177
.decrement_refcount mod_mem_cache.c 6.78 1 0.1 176
.apr_table_setn glink.s 2.82 10 0.1 169
._ptrgl ptrgl.s 5.49 5 0.1 165
.apr_allocator_mutex_get apr_pools.c 40.50 2 0.1 162
.ap_cache_liststr glink.s 13.06 2 0.1 157
.memcache_gdsf_algorithm mod_mem_cache.c 5.59 2 0.1 156
.apr_array_make apr_tables.c 7.74 1 0.1 155
.apr_pstrmemdup apr_strings.c 3.32 2 0.1 152
.ap_cache_tokstr cache_util.c 3.24 1 0.1 146
.apr_pstrmemdup glink.s 23.58 1 0.1 142
.apr_thread_mutex_unlock thread_mutex.c 2.94 3 0.1 141
.memcmp memcmp.s 3.88 1 0.1 140
.apr_bucket_eos_create apr_buckets_eos.c 3.47 2 0.1 139
.apr_bucket_heap_create apr_buckets_heap.c 2.65 2 0.1 138
.ap_cache_tokstr glink.s 22.00 1 0.1 132
.cache_hash_get glink.s 21.92 1 0.1 132
.__divi64 glink.s 21.58 1 0.1 130
.strlen glink.s 4.25 5 0.1 128
.apr_table_make glink.s 5.31 4 0.1 128
.memcmp glink.s 21.17 1 0.1 127
.minchild cache_pqueue.c 7.22 1 0.1 123
.apr_bucket_shared_copy apr_buckets_refcount.c 1.87 4 0.0 120
.apr_pstrndup apr_strings.c 3.84 1 0.0 119
.ap_cache_liststr cache_util.c 2.80 2 0.0 118
.cache_find cache_cache.c 8.96 1 0.0 116
._Errno glink.s 6.44 3 0.0 116
.select glink.s 19.33 1 0.0 116
.gettimeofday glink.s 19.17 1 0.0 115
.apr_allocator_free glink.s 4.60 4 0.0 110
.apr_thread_mutex_lock glink.s 18.00 1 0.0 108
.apr_pstrdup glink.s 6.00 3 0.0 108
.apr_time_now time.c 4.32 1 0.0 108
.cache_generate_key_default cache_storage.c 6.32 1 0.0 108
.cache_find glink.s 17.46 1 0.0 105
.cache_update cache_cache.c 3.35 1 0.0 104
.apr_bucket_immortal_create apr_buckets_simple.c 4.28 1 0.0 103
.apr_bucket_shared_make apr_buckets_refcount.c 5.69 3 0.0 102
.kwritev glink.s 16.96 1 0.0 102
.apr_bucket_flush_create apr_buckets_flush.c 5.05 1 0.0 101
.apr_bucket_simple_copy glink.s 4.21 4 0.0 101
.ap_set_content_type glink.s 16.50 1 0.0 99
.apr_setsocketopt glink.s 8.19 2 0.0 98
.memset glink.s 8.10 2 0.0 97
.ap_cache_get_cachetype glink.s 16.00 1 0.0 96
.free_proc_chain apr_pools.c 6.79 1 0.0 95
.apr_thread_mutex_lock glink.s 7.77 2 0.0 93
.time_base_to_time libc/POWER/time_base_to_time.c 1.66 1 0.0 93
.memset glink.s 15.42 1 0.0 92
.cache_update glink.s 15.42 1 0.0 92
.apr_bucket_socket_create apr_buckets_socket.c 4.36 1 0.0 92
.ap_log_error glink.s 3.70 4 0.0 89
.apr_palloc glink.s 7.06 2 0.0 85
.isdigit glink.s 13.92 1 0.0 84
.apr_bucket_heap_create glink.s 6.92 2 0.0 83
.cache_pq_percolate_down cache_pqueue.c 4.85 1 0.0 82
.apr_bucket_free glink.s 3.40 4 0.0 82
.ap_add_output_filter glink.s 13.42 1 0.0 80
.cache_pq_change_priority cache_pqueue.c 3.75 1 0.0 79
.cache_read_entity_headers cache_storage.c 3.58 1 0.0 79
.apr_atomic_dec glink.s 12.42 1 0.0 74
.memchr glink.s 12.29 1 0.0 74
.strncasecmp glink.s 11.96 1 0.0 72
.apr_table_get glink.s 2.37 5 0.0 71
.apr_bucket_eos_make apr_buckets_eos.c 4.79 2 0.0 67
.apr_bucket_eos_create glink.s 10.92 1 0.0 66
.simple_bucket_read apr_buckets_simple.c 4.09 2 0.0 66
.ap_set_keepalive glink.s 10.71 1 0.0 64
.cache_read_entity_body cache_storage.c 6.33 1 0.0 63
.apr_bucket_immortal_create glink.s 10.29 1 0.0 62
.apr_atomic_inc glink.s 10.12 1 0.0 61
.apr_allocator_alloc apr_pools.c 15.06 4 0.0 60
.apr_getsocketopt glink.s 9.62 1 0.0 58
.ap_pass_brigade glink.s 4.73 2 0.0 57
.apr_bucket_immortal_make apr_buckets_simple.c 7.18 1 0.0 50
.apr_brigade_create glink.s 8.17 1 0.0 49
.cache_hash_get cache_hash.c 3.46 1 0.0 48
.apr_getsocketopt sockopt.c 7.92 1 0.0 48
.apr_pstrndup glink.s 7.75 1 0.0 46
.ap_get_output_filter_handle glink.s 3.83 2 0.0 46
.ap_basic_http_header glink.s 7.67 1 0.0 46
.brigade_cleanup apr_brigade.c 11.25 4 0.0 45
.apr_brigade_write glink.s 2.17 3 0.0 39
.strcasecmp glink.s 6.29 1 0.0 38
.apr_bucket_socket_make apr_buckets_socket.c 5.18 1 0.0 36
.ap_remove_output_filter glink.s 5.83 1 0.0 35
.apr_psprintf apr_pools.c 1.83 1 0.0 33
.apr_pool_cleanup_register glink.s 5.38 1 0.0 32
.isspace glink.s 5.38 1 0.0 32
.strchr glink.s 5.21 1 0.0 31
.cache_read_entity_body glink.s 4.92 1 0.0 30
.bzero memset.s 9.58 1 0.0 29
.apr_bucket_destroy_noop apr_buckets.c 7.00 4 0.0 28
.apr_allocator_free apr_pools.c 7.00 4 0.0 28
.apr_thread_mutex_unlock glink.s 2.17 2 0.0 26
.apr_allocator_owner_get apr_pools.c 5.00 2 0.0 20
.memcache_inc_frequency mod_mem_cache.c 2.14 1 0.0 15
.apr_bucket_flush_make apr_buckets_flush.c 2.00 1 0.0 14
.memset glink.s 2.17 1 0.0 13
.cache_select_url glink.s 2.17 1 0.0 13
.apr_pstrdup glink.s 2.17 1 0.0 13
.apr_thread_mutex_unlock glink.s 2.17 1 0.0 13
.apr_brigade_puts glink.s 2.17 1 0.0 13
.apr_bucket_heap_make glink.s 2.17 1 0.0 13
.cache_pq_change_priority glink.s 2.17 1 0.0 13
.memcache_get_pos mod_mem_cache.c 4.00 1 0.0 12
.eos_bucket_read apr_buckets_eos.c 2.75 1 0.0 11
RE: Apache 2 cycle vs instruction profiling (2.0.40-dev)
Posted by Bill Stoddard <bi...@wstoddard.com>.
> On Tue, 2002-07-02 at 21:09, Bill Stoddard wrote:
>
> > .ap_rgetline_core protocol.c 3.32 6
> 1.4 3428
>
> I'll try the persistent-temp-brigade approach for ap_rgetline_core()
> to see how much it helps.
>
> > .get_filter_handle util_filter.c 4.62 2
> 1.1 2730
>
Hacked mod_cache. I use this in removing ap_http_header_filter. I've not
spent a lot of time on this part of the hack to see if there is a better
way.
> Is this being called from a custom module?
>
> > .apr_brigade_puts glink.s 6.88 4
> 0.1 165
>
> Does this test include your hack to bypass the normal writing of the
> response header? (Or is apr_brigade_puts() just in much better shape
> now?)
This includes my hack to mod_cache to apr_brigade_write() a bunch of
pre-built headers. It's performance is still pretty bad, I am just not
calling it as often.
>
> > .apr_table_get apr_tables.c 3.26 17
> 1.8 4255
>
> Here's some more information on the performance of apr_table_get():
> For typical requests, we do an average of 0.25 strcasecmp() ops
> per apr_table_get(). The good news is that the checksum code is
> doing its job by eliminating the need for most string comparisons.
> The bad news is that we're typically doing N integer checksum
> comparisons for an N-element table (i.e., at least 3/4 of all
> apr_table_get() calls don't find a match, which means that we
> have to scan through the entire table).
>
> I can think of three ways to potentially speed up apr_table_get()
>
> 1. Keep the basic design the same, but optimize the checksum
> computation. We might be able to replace the 4 character
> reads from memory with a single integer read from memory
> in the common case where the start of the string is
> word-aligned.
>
> 2. Add some form of optional indexing to the tables.
>
> 3. Add an "is_sorted" flag to apr_table_t, and do a binary
> search in apr_table_get() if the table is sorted. (I
> think we can get the request headers sorted for free as
> a side effect of the apr_table_overlap() implementation.)
>
> > .apr_palloc apr_pools.c 2.13 95
> 1.5 3641
>
> In my last round of profiling, 30+% of the apr_palloc() cycles were
> related to brigade creation. Thus the persistent-brigade hack for
> ap_rgetline_core() may provide a measurable improvement here.
>
> --Brian
>
>
Re: Apache 2 cycle vs instruction profiling (2.0.40-dev)
Posted by Brian Pane <bp...@pacbell.net>.
On Tue, 2002-07-02 at 21:09, Bill Stoddard wrote:
> .ap_rgetline_core protocol.c 3.32 6 1.4 3428
I'll try the persistent-temp-brigade approach for ap_rgetline_core()
to see how much it helps.
> .get_filter_handle util_filter.c 4.62 2 1.1 2730
Is this being called from a custom module?
> .apr_brigade_puts glink.s 6.88 4 0.1 165
Does this test include your hack to bypass the normal writing of the
response header? (Or is apr_brigade_puts() just in much better shape
now?)
> .apr_table_get apr_tables.c 3.26 17 1.8 4255
Here's some more information on the performance of apr_table_get():
For typical requests, we do an average of 0.25 strcasecmp() ops
per apr_table_get(). The good news is that the checksum code is
doing its job by eliminating the need for most string comparisons.
The bad news is that we're typically doing N integer checksum
comparisons for an N-element table (i.e., at least 3/4 of all
apr_table_get() calls don't find a match, which means that we
have to scan through the entire table).
I can think of three ways to potentially speed up apr_table_get()
1. Keep the basic design the same, but optimize the checksum
computation. We might be able to replace the 4 character
reads from memory with a single integer read from memory
in the common case where the start of the string is
word-aligned.
2. Add some form of optional indexing to the tables.
3. Add an "is_sorted" flag to apr_table_t, and do a binary
search in apr_table_get() if the table is sorted. (I
think we can get the request headers sorted for free as
a side effect of the apr_table_overlap() implementation.)
> .apr_palloc apr_pools.c 2.13 95 1.5 3641
In my last round of profiling, 30+% of the apr_palloc() cycles were
related to brigade creation. Thus the persistent-brigade hack for
ap_rgetline_core() may provide a measurable improvement here.
--Brian
RE: Apache 2 cycle vs instruction profiling (2.0.40-dev)
Posted by Bill Stoddard <bi...@wstoddard.com>.
Shlib Subroutine Source File Ratio Enter % Cycles
================ =========== ===== ===== ==========
.memset memset.s 5.63 9 6.3 15311
Hummm... here is a snip from the flow trace...
<snip>
1003923 2689 sendrecv.c 99 17 .......[0]apr_recv
1003925 2703 sendrecv.c 119 14
........[0]apr_wait_for_io_or_timeout
1003927 2709 glink.s 185 6 .........[0]bzero
1003928 2712 memset.s 29 3 .........[0]bzero
1003929 4785 memset.s 10326 2073 .........*[0]memset
1004959 4803 sendrecv.c 65 18
........[14]apr_wait_for_io_or_timeout
1004961 4809 glink.s 128 6 .........[0]__divi64
1004962 4908 divi64.s 295 99 .........[0]__divi64
1004982 4917 sendrecv.c 13 9
........[32]apr_wait_for_io_or_timeout
1004983 4923 glink.s 83 6 .........[0]select
==> KERNEL
</snip>
Here is the source that corresponds to the flow trace:
apr_status_t apr_wait_for_io_or_timeout(apr_socket_t *sock, int for_read)
{
struct timeval tv, *tvptr;
fd_set fdset;
int srv;
do {
FD_ZERO(&fdset);
FD_SET(sock->socketdes, &fdset);
if (sock->timeout < 0) {
tvptr = NULL;
}
else {
tv.tv_sec = sock->timeout / APR_USEC_PER_SEC;
tv.tv_usec = sock->timeout % APR_USEC_PER_SEC;
tvptr = &tv;
}
srv = select(sock->socketdes + 1,
for_read ? &fdset : NULL,
for_read ? NULL : &fdset,
NULL,
tvptr);
/* TODO - timeout should be smaller on repeats of this loop */
} while (srv == -1 && errno == EINTR);
I am -very- suprised that FD_SET is so wicked expensive. This accounts for
10,000+ of the 15,311 cycles of memset. Going to bounce this one off the AIX
dev team and see what I get back.
Bill