Thanks Greg for the response, my comments inline…
Thanks, Guang On Tue, Feb 18, 2014 at 7:24 AM, Guang Yang < yguang11@xxxxxxxxx> wrote: Hi ceph-users, We are using Ceph (radosgw) to store user generated images, as GET latency is critical for us, most recently I did some investigation over the GET path to understand where time spend.
I first confirmed that the latency came from OSD (read op), so that we instrumented code to trace the GET request (read op at OSD side, to be more specific,
How'd you instrument it? Are you aware of the OpTracker system that records and can output important events?
I just add some time measurement code before and after some calls, here is a the diff (I ported the lock contention fix to dumpling on my test, please ignore that) - https://github.com/ceph/ceph/pull/1281/filesYeah we are using OpTracker as well (dump history op), however, from the dumped history op, it is a little bit hard to tell where does the time spend (it is between started and finish). As read latency is critical for us, we would like to check next level details so that we add some checking for lock / file system call. I am also thinking to refine the code more log to reflect where time spent at filestore side, are you interested in such type of code change? (it took me some time to trouble shoot the get latency and finally I need to add some more log to get a picture). each object with size [512K + 4M * x] are splitted into [1 + x] chunks, each chunk needs one read op ), for each read op, it needs to go through the following steps: 1. Dispatch and take by a op thread to process (process not started). 0 - 20 ms, 94% 20 - 50 ms, 2% 50 - 100 ms, 2% 100ms+ , 2% For those having 20ms+ latency, half of them are due to waiting for pg lock (https://github.com/ceph/ceph/blob/dumpling/src/osd/OSD.cc#L7089), another half are yet to be investigated.
The PG lock conflict means that there's something else happening in the PG at the same time; that's a logical contention issue. However, 20ms is a long time, so if you can figure out what else the PG is doing during that time it'd be interesting
I haven’t deep dive that yet (that is a relatively small percentage comparing to the second part (which comes from filestore i/o slowness due to Dentry / inode cache), my interoperation is that as we serialize PG operation and there are some ops taking (like caused by the below), so that there is a chance the op are trying to operate on the same pg might wait for some time. BTW, what is the long term strategy for Ceph to support small files (which motivated Facebook to build haystack to solve)? Yeah I am aware of that and we are extremely interested in the effort as well. Basically our use case is: 1. Get latency is more critical than PUT latency. 2. Our work load is mainly small files (95% are less than 512KB). -Greg Software Engineer #42 @ http://inktank.com | http://ceph.com 3. Get more xattrs, this is fast due to previous fd cache (rarely > 1ms).
4. Read the data. 0 - 20 ms, 84% 20 - 50 ms, 10% 50 - 100 ms, 4% 100ms+ , 2%
I decreased vfs_cache_pressure from its default value 100 to 5 to make VFS favor dentry/inode cache over page cache, unfortunately it does not help.
Long story short, most of the long latency read op comes from file system call (for cold data), as our workload mainly stores objects less than 500KB, so that it generates a large bunch of objects.
I would like to ask if people experienced similar issue and if there is any suggestion I can try to boost the GET performance. On the other hand, PUT could be sacrificed.
Thanks, Guang
_______________________________________________ ceph-users mailing list ceph-users@xxxxxxxxxxxxxx http://lists.ceph.com/listinfo.cgi/ceph-users-ceph.com
|