In the test I did on another box, harder to replace the binaries on the box I
was benchmarking, I am see the same Vol* come back on the different URLs I
tested. It looks like it is using only 1 mutex for locking. I have 1GB of ram
cache and 10GB of disk cache in this test, if that matters.
[Jul 30 21:41:00.463] Server {0x7f333e441700} DEBUG: (bcall) key_to_vol
hash_table: 0x7f3318001e00 hash: 20490 vol: 0x7f3328004610
[Jul 30 21:41:01.793] Server {0x7f333e23f700} DEBUG: (bcall) key_to_vol
hash_table: 0x7f3318001e00 hash: 9142 vol: 0x7f3328004610
[Jul 30 21:54:07.196] Server {0x7f333de3b700} DEBUG: (bcall) key_to_vol
hash_table: 0x7f3318001e00 hash: 304 vol: 0x7f3328004610
[Jul 30 21:54:10.775] Server {0x7f333dd3a700} DEBUG: (bcall) key_to_vol
hash_table: 0x7f3318001e00 hash: 28827 vol: 0x7f3328004610
[Jul 30 21:54:18.033] Server {0x7f333f8c3840} DEBUG: (bcall) key_to_vol
hash_table: 0x7f3318001e00 hash: 20693 vol: 0x7f3328004610
changed code in key_to_vol:
Vol *tmp = host_rec->vols[hash_table[h]];
Debug("bcall", "key_to_vol hash_table: %p hash: %d vol: %p", hash_table, h,
tmp);
return tmp;
-Bryan
On Jul 30, 2012, at 8:10 PM, Bryan Call <bc...@apache.org> wrote:
> When I am doing benchmarking on ATS I am seeing some requests >= 40ms but the
> vast majority are taking <= 1ms. When turning on slow log it looks like the
> issue is around cache. is there any option that I can set to mitigate this
> issue or anything I can do to dig in deeper to find out where the problems is?
>
> [Jul 31 03:01:57.160] Server {0x2ad695824700} ERROR: [36364408] Slow Request:
> url: http://q4.ycpi.bf1.yahoo.net:8124/200_10_0_cache status: 200 unique id:
> bytes: 200 fd: 0 client state: 0 server state: 0 ua_begin: 0.000
> ua_read_header_done: 0.000 cache_open_read_begin: 0.000 cache_open_read_end:
> 0.040 dns_lookup_begin: -1.000 dns_lookup_end: -1.000 server_connect: -1.000
> server_first_read: -1.000 server_read_header_done: -1.000 server_close:
> -1.000 ua_close: 0.040 sm_finish: 0.040
> [Jul 31 03:01:58.440] Server {0x2ad695824700} ERROR: [36556479] Slow Request:
> url: http://q4.ycpi.bf1.yahoo.net:8124/200_10_0_cache status: 200 unique id:
> bytes: 200 fd: 0 client state: 0 server state: 0 ua_begin: 0.000
> ua_read_header_done: 0.000 cache_open_read_begin: 0.000 cache_open_read_end:
> 0.040 dns_lookup_begin: -1.000 dns_lookup_end: -1.000 server_connect: -1.000
> server_first_read: -1.000 server_read_header_done: -1.000 server_close:
> -1.000 ua_close: 0.040 sm_finish: 0.040
>
> Here are the results of the benchmark. This occurs in less then 1% of the
> responses:
> [client bcall@q1 bench]$ fbench -s 120 -c 2 -n 200 -q "200_%d.query"
> q2.ycpi.bf1.yahoo.net 8080
> Starting clients...
> [dummydate]: PROGRESS: fbench: Seconds left 120
> [dummydate]: PROGRESS: fbench: Seconds left 60
> Stopping
> clients........................................................................................................................................................................................................
> Clients stopped.
> *** HTTP keep-alive statistics ***
> connection reuse count -- 17774265
> ***************** Benchmark Summary *****************
> clients: 200
> ran for: 120 seconds
> cycle time: 2 ms
> lower response limit: 0 bytes
> skipped requests: 0
> failed requests: 0
> successful requests: 17774465
> cycles not held: 20219
> minimum response time: 0.09 ms
> maximum response time: 84.21 ms
> average response time: 0.29 ms
> 25 percentile: 0.00 ms
> 50 percentile: 0.00 ms
> 75 percentile: 0.00 ms
> 90 percentile: 0.00 ms
> 95 percentile: 0.00 ms
> 99 percentile: 1.00 ms
> actual query rate: 148175.09 Q/s
> utilization: 21.41 %
> zero hit queries: 0
>
> -Bryan
>
>
>
