Add a tracepoint to log decisions made in cachefiles_prepare_read() about what it's going to request for the next subrequest and why. Signed-off-by: David Howells <dhowells@xxxxxxxxxx> --- fs/cachefiles/io.c | 22 +++++++++++-- fs/cachefiles/main.c | 2 + include/trace/events/cachefiles.h | 64 +++++++++++++++++++++++++++++++++++++ 3 files changed, 85 insertions(+), 3 deletions(-) diff --git a/fs/cachefiles/io.c b/fs/cachefiles/io.c index e5c29c0decea..c05f64cdfd0e 100644 --- a/fs/cachefiles/io.c +++ b/fs/cachefiles/io.c @@ -303,6 +303,7 @@ static int cachefiles_write(struct netfs_cache_resources *cres, static enum netfs_read_source cachefiles_prepare_read(struct netfs_read_subrequest *subreq, loff_t i_size) { + enum cachefiles_prepare_read_trace why; struct netfs_read_request *rreq = subreq->rreq; struct netfs_cache_resources *cres = &rreq->cache_resources; struct cachefiles_object *object; @@ -312,26 +313,31 @@ static enum netfs_read_source cachefiles_prepare_read(struct netfs_read_subreque struct file *file = cachefiles_cres_file(cres); enum netfs_read_source ret = NETFS_DOWNLOAD_FROM_SERVER; loff_t off, to; + ino_t ino = file ? file_inode(file)->i_ino : 0; _enter("%zx @%llx/%llx", subreq->len, subreq->start, i_size); if (subreq->start >= i_size) { ret = NETFS_FILL_WITH_ZEROES; + why = cachefiles_trace_read_after_eof; goto out_no_object; } if (test_bit(FSCACHE_COOKIE_NO_DATA_TO_READ, &cookie->flags)) { __set_bit(NETFS_SREQ_WRITE_TO_CACHE, &subreq->flags); + why = cachefiles_trace_read_no_data; goto out_no_object; } /* The object and the file may be being created in the background. */ if (!file) { + why = cachefiles_trace_read_no_file; if (!fscache_wait_for_operation(cres, FSCACHE_WANT_READ)) goto out_no_object; file = cachefiles_cres_file(cres); if (!file) goto out_no_object; + ino = file_inode(file)->i_ino; } object = cachefiles_cres_object(cres); @@ -340,23 +346,31 @@ static enum netfs_read_source cachefiles_prepare_read(struct netfs_read_subreque off = vfs_llseek(file, subreq->start, SEEK_DATA); if (off < 0 && off >= (loff_t)-MAX_ERRNO) { - if (off == (loff_t)-ENXIO) + if (off == (loff_t)-ENXIO) { + why = cachefiles_trace_read_seek_nxio; goto download_and_store; + } + why = cachefiles_trace_read_seek_error; goto out; } - if (off >= subreq->start + subreq->len) + if (off >= subreq->start + subreq->len) { + why = cachefiles_trace_read_found_hole; goto download_and_store; + } if (off > subreq->start) { off = round_up(off, cache->bsize); subreq->len = off - subreq->start; + why = cachefiles_trace_read_found_part; goto download_and_store; } to = vfs_llseek(file, subreq->start, SEEK_HOLE); - if (to < 0 && to >= (loff_t)-MAX_ERRNO) + if (to < 0 && to >= (loff_t)-MAX_ERRNO) { + why = cachefiles_trace_read_seek_error; goto out; + } if (to < subreq->start + subreq->len) { if (subreq->start + subreq->len >= i_size) @@ -366,6 +380,7 @@ static enum netfs_read_source cachefiles_prepare_read(struct netfs_read_subreque subreq->len = to - subreq->start; } + why = cachefiles_trace_read_have_data; ret = NETFS_READ_FROM_CACHE; goto out; @@ -375,6 +390,7 @@ static enum netfs_read_source cachefiles_prepare_read(struct netfs_read_subreque out: cachefiles_end_secure(cache, saved_cred); out_no_object: + trace_cachefiles_prep_read(subreq, ret, why, ino); return ret; } diff --git a/fs/cachefiles/main.c b/fs/cachefiles/main.c index dc7731812b98..522fda828563 100644 --- a/fs/cachefiles/main.c +++ b/fs/cachefiles/main.c @@ -18,6 +18,8 @@ #include <linux/statfs.h> #include <linux/sysctl.h> #include <linux/miscdevice.h> +#include <linux/netfs.h> +#include <trace/events/netfs.h> #define CREATE_TRACE_POINTS #include "internal.h" diff --git a/include/trace/events/cachefiles.h b/include/trace/events/cachefiles.h index d98adabce92e..d63e5fb46d27 100644 --- a/include/trace/events/cachefiles.h +++ b/include/trace/events/cachefiles.h @@ -60,6 +60,17 @@ enum cachefiles_trunc_trace { cachefiles_trunc_shrink, }; +enum cachefiles_prepare_read_trace { + cachefiles_trace_read_after_eof, + cachefiles_trace_read_found_hole, + cachefiles_trace_read_found_part, + cachefiles_trace_read_have_data, + cachefiles_trace_read_no_data, + cachefiles_trace_read_no_file, + cachefiles_trace_read_seek_error, + cachefiles_trace_read_seek_nxio, +}; + #endif /* @@ -103,6 +114,17 @@ enum cachefiles_trunc_trace { EM(cachefiles_trunc_dio_adjust, "DIOADJ") \ E_(cachefiles_trunc_shrink, "SHRINK") +#define cachefiles_prepare_read_traces \ + EM(cachefiles_trace_read_after_eof, "after-eof ") \ + EM(cachefiles_trace_read_found_hole, "found-hole") \ + EM(cachefiles_trace_read_found_part, "found-part") \ + EM(cachefiles_trace_read_have_data, "have-data ") \ + EM(cachefiles_trace_read_no_data, "no-data ") \ + EM(cachefiles_trace_read_no_file, "no-file ") \ + EM(cachefiles_trace_read_seek_error, "seek-error") \ + E_(cachefiles_trace_read_seek_nxio, "seek-enxio") + + /* * Export enum symbols via userspace. */ @@ -115,6 +137,7 @@ cachefiles_obj_kill_traces; cachefiles_obj_ref_traces; cachefiles_coherency_traces; cachefiles_trunc_traces; +cachefiles_prepare_read_traces; /* * Now redefine the EM() and E_() macros to map the enums to the strings that @@ -324,6 +347,47 @@ TRACE_EVENT(cachefiles_coherency, __entry->content) ); +TRACE_EVENT(cachefiles_prep_read, + TP_PROTO(struct netfs_read_subrequest *sreq, + enum netfs_read_source source, + enum cachefiles_prepare_read_trace why, + ino_t cache_inode), + + TP_ARGS(sreq, source, why, cache_inode), + + TP_STRUCT__entry( + __field(unsigned int, rreq ) + __field(unsigned short, index ) + __field(unsigned short, flags ) + __field(enum netfs_read_source, source ) + __field(enum cachefiles_prepare_read_trace, why ) + __field(size_t, len ) + __field(loff_t, start ) + __field(unsigned int, netfs_inode ) + __field(unsigned int, cache_inode ) + ), + + TP_fast_assign( + __entry->rreq = sreq->rreq->debug_id; + __entry->index = sreq->debug_index; + __entry->flags = sreq->flags; + __entry->source = source; + __entry->why = why; + __entry->len = sreq->len; + __entry->start = sreq->start; + __entry->netfs_inode = sreq->rreq->inode->i_ino; + __entry->cache_inode = cache_inode; + ), + + TP_printk("R=%08x[%u] %s %s f=%02x s=%llx %zx ni=%x b=%x", + __entry->rreq, __entry->index, + __print_symbolic(__entry->source, netfs_sreq_sources), + __print_symbolic(__entry->why, cachefiles_prepare_read_traces), + __entry->flags, + __entry->start, __entry->len, + __entry->netfs_inode, __entry->cache_inode) + ); + TRACE_EVENT(cachefiles_read, TP_PROTO(struct cachefiles_object *obj, struct inode *backer,