I'm just trying to understand the steps each IO goes through and have been
looking at the output dump historic ops command from the admin socket.
There's a couple of steps I'm not quite sure what they mean and also
slightly puzzled by the delay and was wondering if anybody could share some
knowledge around this.
Here is what I think I understand so far:
Initiated = When the OSD received the OP
Queued for PG / Reached PG / Started = This seems to be how long the OSD has
to wait to get a lock on the PG before actually starting the write. Correct?
Is there any perf stats to track this number? And why do I see a 150ms delay
before started. Am I possibly hitting some sort of queue on the PG? Is this
just a large queue of requests on the PG that are waiting to be written to
the journal? Any tips to reduce this?
Waiting for Sub Ops = Self-explanatory, its waiting for replica OSD's to
apply the op to journal
commit_queued_for_journal_write/ write_thread_in_journal_buffer/
journaled_completion_queued/ op_commit = How long it takes to queue and
write to the journal. In example case its 4ms....seems very high for s3700
SSD? Maybe lots of ops are queued up? Most other ops show this <1ms.
sub_op_commit_rec = This is where we hear back from the replica OSD's
op_applied/done = We have finished so send ACK back to client
Thanks for any insight anyone can offer.
Nick
Sample Op
"description": "osd_op(client.9539566.0:292915056
rb.0.265a6.2ae8944a.000000072421 [] 0.c1a473f3
ack+ondisk+write+known_if_redirected e51777)",
"initiated_at": "2016-02-25 17:02:53.017589",
"age": 445.814991,
"duration": 0.164949,
"type_data": [
"commit sent; apply or cleanup",
{
"client": "client.9539566",
"tid": 292915056
},
[
{
"time": "2016-02-25 17:02:53.017589",
"event": "initiated"
},
{
"time": "2016-02-25 17:02:53.017960",
"event": "queued_for_pg"
},
{
"time": "2016-02-25 17:02:53.018029",
"event": "reached_pg"
},
{
"time": "2016-02-25 17:02:53.173131",
"event": "started"
},
{
"time": "2016-02-25 17:02:53.175146",
"event": "waiting for subops from 24,43"
},
{
"time": "2016-02-25 17:02:53.177185",
"event": "commit_queued_for_journal_write"
},
{
"time": "2016-02-25 17:02:53.177285",
"event": "write_thread_in_journal_buffer"
},
{
"time": "2016-02-25 17:02:53.177649",
"event": "journaled_completion_queued"
},
{
"time": "2016-02-25 17:02:53.181831",
"event": "op_commit"
},
{
"time": "2016-02-25 17:02:53.181958",
"event": "sub_op_commit_rec from 43"
},
{
"time": "2016-02-25 17:02:53.182257",
"event": "sub_op_commit_rec from 24"
},
{
"time": "2016-02-25 17:02:53.182491",
"event": "commit_sent"
},
{
"time": "2016-02-25 17:02:53.182512",
"event": "op_applied"
},
{
"time": "2016-02-25 17:02:53.182538",
"event": "done"
}
]
]
_______________________________________________
ceph-users mailing list
ceph-users@xxxxxxxxxxxxxx
http://lists.ceph.com/listinfo.cgi/ceph-users-ceph.com
