when I user rest bench test RGW performance with this argument:
   ./rest-bench --access-key=ak --secret=sk  --bucket=bucket_name --seconds=600 
-t 200 -b 524288 -no-cleanup write
test result:
Total time run:         362.962324
Total writes made:      48189
Write size:             524288
Bandwidth (MB/sec):     66.383 
Stddev Bandwidth:       40.7776
Max bandwidth (MB/sec): 173
Min bandwidth (MB/sec): 0
Average Latency:        1.50435
Stddev Latency:         0.910731
Max latency:            9.12276
Min latency:            0.19867

my environment is 4 host and 40  disk(osd)。

 but test result is very bad, average latency is 1.5 seconds 。and I find write 
obj metadate is very slowly。because it  puts so many object to one bucket,
 we know writing object metadate can call method “bucket_prepare_op”,and test 
find this op is very slowly。

I find  the osd which contain bucket-obj。and   see the “bucket_prepare_op”by 
dump_historic_ops 
{ "description": "osd_op(client.4742.0:87615 .dir.default.4243.3 [call 
rgw.bucket_prepare_op] 3.3670fe74 e317)",
          "received_at": "2014-06-30 13:35:55.447192",
          "age": "51.110431",
          "duration": "4.092646",
          "type_data": [
                "commit sent; apply or cleanup",
                { "client": "client.4742",
                  "tid": 87615},
                [
                    { "time": "2014-06-30 13:35:55.447402",
                      "event": "waiting_for_osdmap"},
                    { "time": "2014-06-30 13:35:55.447409",
                      "event": "queue op_wq"},
                    { "time": "2014-06-30 13:35:55.902491",
                      "event": "reached_pg"},
                    { "time": "2014-06-30 13:35:55.902512",
                      "event": "started"},
                    { "time": "2014-06-30 13:35:55.902515",
                      "event": "started"},
                    { "time": "2014-06-30 13:35:55.911850",
                      "event": "waiting for subops from [40,43]"},
                    { "time": "2014-06-30 13:35:55.912052",
                      "event": "commit_queued_for_journal_write"},
                    { "time": "2014-06-30 13:35:55.912116",
                      "event": "write_thread_in_journal_buffer"},
                    { "time": "2014-06-30 13:35:55.924200",
                      "event": "journaled_completion_queued"},
                    { "time": "2014-06-30 13:35:55.924207",
                      "event": "journal first callback"},
                    { "time": "2014-06-30 13:35:55.924215",
                      "event": "queuing ondisk"},
                    { "time": "2014-06-30 13:35:56.142174",
                      "event": "sub_op_commit_rec"},
                    { "time": "2014-06-30 13:35:56.177000",
                      "event": "sub_op_commit_rec"},
                    { "time": "2014-06-30 13:35:59.535374",
                      "event": "op_commit"},
                    { "time": "2014-06-30 13:35:59.535404",
                      "event": "commit_sent"},
                    { "time": "2014-06-30 13:35:59.539765",
                      "event": "op_applied"},
                    { "time": "2014-06-30 13:35:59.539838",
                      "event": "done"}]]},
so why  from "journaled_completion_queued" to "op_commit" is very slowly, and 
what happened?

thanks
_______________________________________________
ceph-users mailing list
ceph-users@lists.ceph.com
http://lists.ceph.com/listinfo.cgi/ceph-users-ceph.com

Reply via email to