From: David Howells <dhowells@redhat.com> To: Trond Myklebust <trondmy@hammerspace.com>, Anna Schumaker <anna.schumaker@netapp.com>, Steve French <sfrench@samba.org>, Dominique Martinet <asmadeus@codewreck.org> Cc: dhowells@redhat.com, Jeff Layton <jlayton@redhat.com>, David Wysochanski <dwysocha@redhat.com>, Matthew Wilcox <willy@infradead.org>, Alexander Viro <viro@zeniv.linux.org.uk>, linux-cachefs@redhat.com, linux-afs@lists.infradead.org, linux-nfs@vger.kernel.org, linux-cifs@vger.kernel.org, ceph-devel@vger.kernel.org, v9fs-developer@lists.sourceforge.net, linux-fsdevel@vger.kernel.org, linux-kernel@vger.kernel.org Subject: [PATCH 07/32] netfs: Add tracepoints Date: Mon, 25 Jan 2021 21:32:14 +0000 Message-ID: <161161033468.2537118.14021843889844001905.stgit@warthog.procyon.org.uk> (raw) In-Reply-To: <161161025063.2537118.2009249444682241405.stgit@warthog.procyon.org.uk> Add three tracepoints to track the activity of the read helpers: (1) netfs/netfs_read This logs entry to the read helpers and also expansion of the range in a readahead request. (2) netfs/netfs_rreq This logs the progress of netfs_read_request objects which track read requests. A read request may be a compound of multiple subrequests. (3) netfs/netfs_sreq This logs the progress of netfs_read_subrequest objects, which track the contributions from various sources to a read request. Signed-off-by: David Howells <dhowells@redhat.com> --- fs/netfs/read_helper.c | 28 ++++++ include/linux/netfs.h | 2 include/trace/events/netfs.h | 199 ++++++++++++++++++++++++++++++++++++++++++ 3 files changed, 229 insertions(+) create mode 100644 include/trace/events/netfs.h diff --git a/fs/netfs/read_helper.c b/fs/netfs/read_helper.c index e5264e9d8912..2a90314ea36f 100644 --- a/fs/netfs/read_helper.c +++ b/fs/netfs/read_helper.c @@ -16,6 +16,8 @@ #include <linux/task_io_accounting_ops.h> #include <linux/netfs.h> #include "internal.h" +#define CREATE_TRACE_POINTS +#include <trace/events/netfs.h> MODULE_DESCRIPTION("Network fs support"); MODULE_AUTHOR("Red Hat, Inc."); @@ -38,6 +40,7 @@ static struct netfs_read_request *netfs_alloc_read_request( const struct netfs_read_request_ops *ops, void *netfs_priv, struct file *file) { + static atomic_t debug_ids; struct netfs_read_request *rreq; rreq = kzalloc(sizeof(struct netfs_read_request), GFP_KERNEL); @@ -46,6 +49,7 @@ static struct netfs_read_request *netfs_alloc_read_request( rreq->netfs_priv = netfs_priv; rreq->inode = file_inode(file); rreq->i_size = i_size_read(rreq->inode); + rreq->debug_id = atomic_inc_return(&debug_ids); INIT_LIST_HEAD(&rreq->subrequests); INIT_WORK(&rreq->work, netfs_rreq_work); refcount_set(&rreq->usage, 1); @@ -80,6 +84,7 @@ static void netfs_free_read_request(struct work_struct *work) netfs_rreq_clear_subreqs(rreq); if (rreq->netfs_priv) rreq->netfs_ops->cleanup(rreq->mapping, rreq->netfs_priv); + trace_netfs_rreq(rreq, netfs_rreq_trace_free); kfree(rreq); } @@ -121,6 +126,7 @@ static void netfs_get_read_subrequest(struct netfs_read_subrequest *subreq) static void __netfs_put_subrequest(struct netfs_read_subrequest *subreq) { + trace_netfs_sreq(subreq, netfs_sreq_trace_free); netfs_put_read_request(subreq->rreq); kfree(subreq); } @@ -175,6 +181,7 @@ static void netfs_read_from_server(struct netfs_read_request *rreq, */ static void netfs_rreq_completed(struct netfs_read_request *rreq) { + trace_netfs_rreq(rreq, netfs_rreq_trace_done); netfs_rreq_clear_subreqs(rreq); netfs_put_read_request(rreq); } @@ -213,6 +220,8 @@ static void netfs_rreq_unlock(struct netfs_read_request *rreq) iopos = 0; subreq_failed = (subreq->error < 0); + trace_netfs_rreq(rreq, netfs_rreq_trace_unlock); + rcu_read_lock(); xas_for_each(&xas, page, last_page) { unsigned int pgpos = (page->index - start_page) * PAGE_SIZE; @@ -269,6 +278,8 @@ static void netfs_rreq_short_read(struct netfs_read_request *rreq, __clear_bit(NETFS_SREQ_SHORT_READ, &subreq->flags); __set_bit(NETFS_SREQ_SEEK_DATA_READ, &subreq->flags); + trace_netfs_sreq(subreq, netfs_sreq_trace_resubmit_short); + netfs_get_read_subrequest(subreq); atomic_inc(&rreq->nr_rd_ops); netfs_read_from_server(rreq, subreq); @@ -284,6 +295,8 @@ static bool netfs_rreq_perform_resubmissions(struct netfs_read_request *rreq) WARN_ON(in_softirq()); + trace_netfs_rreq(rreq, netfs_rreq_trace_resubmit); + /* We don't want terminating submissions trying to wake us up whilst * we're still going through the list. */ @@ -296,6 +309,7 @@ static bool netfs_rreq_perform_resubmissions(struct netfs_read_request *rreq) break; subreq->source = NETFS_DOWNLOAD_FROM_SERVER; subreq->error = 0; + trace_netfs_sreq(subreq, netfs_sreq_trace_download_instead); netfs_get_read_subrequest(subreq); atomic_inc(&rreq->nr_rd_ops); netfs_read_from_server(rreq, subreq); @@ -320,6 +334,8 @@ static bool netfs_rreq_perform_resubmissions(struct netfs_read_request *rreq) */ static void netfs_rreq_assess(struct netfs_read_request *rreq) { + trace_netfs_rreq(rreq, netfs_rreq_trace_assess); + again: if (!test_bit(NETFS_RREQ_FAILED, &rreq->flags) && test_bit(NETFS_RREQ_INCOMPLETE_IO, &rreq->flags)) { @@ -402,6 +418,8 @@ void netfs_subreq_terminated(struct netfs_read_subrequest *subreq, set_bit(NETFS_RREQ_WRITE_TO_CACHE, &rreq->flags); out: + trace_netfs_sreq(subreq, netfs_sreq_trace_terminated); + /* If we decrement nr_rd_ops to 0, the ref belongs to us. */ u = atomic_dec_return(&rreq->nr_rd_ops); if (u == 0) @@ -490,6 +508,7 @@ netfs_rreq_prepare_read(struct netfs_read_request *rreq, out: subreq->source = source; + trace_netfs_sreq(subreq, netfs_sreq_trace_prepare); return source; } @@ -530,6 +549,7 @@ static bool netfs_rreq_submit_slice(struct netfs_read_request *rreq, rreq->submitted += subreq->len; + trace_netfs_sreq(subreq, netfs_sreq_trace_submit); switch (source) { case NETFS_FILL_WITH_ZEROES: netfs_fill_with_zeroes(rreq, subreq); @@ -572,6 +592,9 @@ static void netfs_rreq_expand(struct netfs_read_request *rreq, readahead_expand(ractl, rreq->start, rreq->len); rreq->start = readahead_pos(ractl); rreq->len = readahead_length(ractl); + + trace_netfs_read(rreq, readahead_pos(ractl), readahead_length(ractl), + netfs_read_trace_expanded); } } @@ -613,6 +636,9 @@ void netfs_readahead(struct readahead_control *ractl, rreq->start = readahead_pos(ractl); rreq->len = readahead_length(ractl); + trace_netfs_read(rreq, readahead_pos(ractl), readahead_length(ractl), + netfs_read_trace_readahead); + netfs_rreq_expand(rreq, ractl); atomic_set(&rreq->nr_rd_ops, 1); @@ -684,6 +710,8 @@ int netfs_readpage(struct file *file, rreq->start = page->index * PAGE_SIZE; rreq->len = thp_size(page); + trace_netfs_read(rreq, rreq->start, rreq->len, netfs_read_trace_readpage); + netfs_get_read_request(rreq); atomic_set(&rreq->nr_rd_ops, 1); diff --git a/include/linux/netfs.h b/include/linux/netfs.h index 8d27ad82e0c3..0779cf082101 100644 --- a/include/linux/netfs.h +++ b/include/linux/netfs.h @@ -63,6 +63,8 @@ struct netfs_read_request { struct address_space *mapping; /* The mapping being accessed */ struct list_head subrequests; /* Requests to fetch I/O from disk or net */ void *netfs_priv; /* Private data for the netfs */ + unsigned int debug_id; + unsigned int cookie_debug_id; atomic_t nr_rd_ops; /* Number of read ops in progress */ size_t submitted; /* Amount submitted for I/O so far */ size_t len; /* Length of the request */ diff --git a/include/trace/events/netfs.h b/include/trace/events/netfs.h new file mode 100644 index 000000000000..12ad382764c5 --- /dev/null +++ b/include/trace/events/netfs.h @@ -0,0 +1,199 @@ +/* SPDX-License-Identifier: GPL-2.0-or-later */ +/* Network filesystem support module tracepoints + * + * Copyright (C) 2021 Red Hat, Inc. All Rights Reserved. + * Written by David Howells (dhowells@redhat.com) + */ +#undef TRACE_SYSTEM +#define TRACE_SYSTEM netfs + +#if !defined(_TRACE_NETFS_H) || defined(TRACE_HEADER_MULTI_READ) +#define _TRACE_NETFS_H + +#include <linux/tracepoint.h> + +/* + * Define enums for tracing information. + */ +#ifndef __NETFS_DECLARE_TRACE_ENUMS_ONCE_ONLY +#define __NETFS_DECLARE_TRACE_ENUMS_ONCE_ONLY + +enum netfs_read_trace { + netfs_read_trace_expanded, + netfs_read_trace_readahead, + netfs_read_trace_readpage, +}; + +enum netfs_rreq_trace { + netfs_rreq_trace_assess, + netfs_rreq_trace_done, + netfs_rreq_trace_free, + netfs_rreq_trace_resubmit, + netfs_rreq_trace_unlock, + netfs_rreq_trace_unmark, + netfs_rreq_trace_write, +}; + +enum netfs_sreq_trace { + netfs_sreq_trace_download_instead, + netfs_sreq_trace_free, + netfs_sreq_trace_prepare, + netfs_sreq_trace_resubmit_short, + netfs_sreq_trace_submit, + netfs_sreq_trace_terminated, + netfs_sreq_trace_write, + netfs_sreq_trace_write_term, +}; + +#endif + +#define netfs_read_traces \ + EM(netfs_read_trace_expanded, "EXPANDED ") \ + EM(netfs_read_trace_readahead, "READAHEAD") \ + E_(netfs_read_trace_readpage, "READPAGE ") + +#define netfs_rreq_traces \ + EM(netfs_rreq_trace_assess, "ASSESS") \ + EM(netfs_rreq_trace_done, "DONE ") \ + EM(netfs_rreq_trace_free, "FREE ") \ + EM(netfs_rreq_trace_resubmit, "RESUBM") \ + EM(netfs_rreq_trace_unlock, "UNLOCK") \ + EM(netfs_rreq_trace_unmark, "UNMARK") \ + E_(netfs_rreq_trace_write, "WRITE ") + +#define netfs_sreq_sources \ + EM(NETFS_FILL_WITH_ZEROES, "ZERO") \ + EM(NETFS_DOWNLOAD_FROM_SERVER, "DOWN") \ + EM(NETFS_READ_FROM_CACHE, "READ") \ + E_(NETFS_INVALID_READ, "INVL") \ + +#define netfs_sreq_traces \ + EM(netfs_sreq_trace_download_instead, "RDOWN") \ + EM(netfs_sreq_trace_free, "FREE ") \ + EM(netfs_sreq_trace_prepare, "PREP ") \ + EM(netfs_sreq_trace_resubmit_short, "SHORT") \ + EM(netfs_sreq_trace_submit, "SUBMT") \ + EM(netfs_sreq_trace_terminated, "TERM ") \ + EM(netfs_sreq_trace_write, "WRITE") \ + E_(netfs_sreq_trace_write_term, "WTERM") + + +/* + * Export enum symbols via userspace. + */ +#undef EM +#undef E_ +#define EM(a, b) TRACE_DEFINE_ENUM(a); +#define E_(a, b) TRACE_DEFINE_ENUM(a); + +netfs_read_traces; +netfs_rreq_traces; +netfs_sreq_sources; +netfs_sreq_traces; + +/* + * Now redefine the EM() and E_() macros to map the enums to the strings that + * will be printed in the output. + */ +#undef EM +#undef E_ +#define EM(a, b) { a, b }, +#define E_(a, b) { a, b } + +TRACE_EVENT(netfs_read, + TP_PROTO(struct netfs_read_request *rreq, + loff_t start, size_t len, + enum netfs_read_trace what), + + TP_ARGS(rreq, start, len, what), + + TP_STRUCT__entry( + __field(unsigned int, rreq ) + __field(unsigned int, cookie ) + __field(loff_t, start ) + __field(size_t, len ) + __field(enum netfs_read_trace, what ) + ), + + TP_fast_assign( + __entry->rreq = rreq->debug_id; + __entry->cookie = rreq->cookie_debug_id; + __entry->start = start; + __entry->len = len; + __entry->what = what; + ), + + TP_printk("R=%08x %s c=%08x s=%llx %zx", + __entry->rreq, + __print_symbolic(__entry->what, netfs_read_traces), + __entry->cookie, + __entry->start, __entry->len) + ); + +TRACE_EVENT(netfs_rreq, + TP_PROTO(struct netfs_read_request *rreq, + enum netfs_rreq_trace what), + + TP_ARGS(rreq, what), + + TP_STRUCT__entry( + __field(unsigned int, rreq ) + __field(unsigned short, flags ) + __field(enum netfs_rreq_trace, what ) + ), + + TP_fast_assign( + __entry->rreq = rreq->debug_id; + __entry->flags = rreq->flags; + __entry->what = what; + ), + + TP_printk("R=%08x %s f=%02x", + __entry->rreq, + __print_symbolic(__entry->what, netfs_rreq_traces), + __entry->flags) + ); + +TRACE_EVENT(netfs_sreq, + TP_PROTO(struct netfs_read_subrequest *sreq, + enum netfs_sreq_trace what), + + TP_ARGS(sreq, what), + + TP_STRUCT__entry( + __field(unsigned int, rreq ) + __field(unsigned short, index ) + __field(short, error ) + __field(unsigned short, flags ) + __field(enum netfs_read_source, source ) + __field(enum netfs_sreq_trace, what ) + __field(size_t, len ) + __field(size_t, transferred ) + __field(loff_t, start ) + ), + + TP_fast_assign( + __entry->rreq = sreq->rreq->debug_id; + __entry->index = sreq->debug_index; + __entry->error = sreq->error; + __entry->flags = sreq->flags; + __entry->source = sreq->source; + __entry->what = what; + __entry->len = sreq->len; + __entry->transferred = sreq->transferred; + __entry->start = sreq->start; + ), + + TP_printk("R=%08x[%u] %s %s f=%02x s=%llx %zx/%zx e=%d", + __entry->rreq, __entry->index, + __print_symbolic(__entry->what, netfs_sreq_traces), + __print_symbolic(__entry->source, netfs_sreq_sources), + __entry->flags, + __entry->start, __entry->transferred, __entry->len, + __entry->error) + ); + +#endif /* _TRACE_NETFS_H */ + +/* This part must be outside protection */ +#include <trace/define_trace.h>
next prev parent reply index Thread overview: 41+ messages / expand[flat|nested] mbox.gz Atom feed top 2021-01-25 21:30 [PATCH 00/32] Network fs helper library & fscache kiocb API [ver #2] David Howells 2021-01-25 21:31 ` [PATCH 01/32] iov_iter: Add ITER_XARRAY David Howells 2021-01-25 21:31 ` [PATCH 02/32] vm: Add wait/unlock functions for PG_fscache David Howells 2021-01-25 21:31 ` [PATCH 03/32] mm: Implement readahead_control pageset expansion David Howells 2021-01-25 21:31 ` [PATCH 04/32] vfs: Export rw_verify_area() for use by cachefiles David Howells 2021-01-25 21:31 ` [PATCH 05/32] netfs: Make a netfs helper module David Howells 2021-01-25 21:32 ` [PATCH 06/32] netfs: Provide readahead and readpage netfs helpers David Howells 2021-01-25 21:32 ` David Howells [this message] 2021-01-25 21:32 ` [PATCH 08/32] netfs: Gather stats David Howells 2021-01-25 21:32 ` [PATCH 09/32] netfs: Add write_begin helper David Howells 2021-01-25 21:32 ` [PATCH 10/32] netfs: Define an interface to talk to a cache David Howells 2021-01-25 21:32 ` [PATCH 11/32] fscache, cachefiles: Add alternate API to use kiocb for read/write to cache David Howells 2021-01-25 21:33 ` [PATCH 12/32] afs: Disable use of the fscache I/O routines David Howells 2021-01-25 21:33 ` [PATCH 13/32] afs: Pass page into dirty region helpers to provide THP size David Howells 2021-01-25 21:33 ` [PATCH 14/32] afs: Print the operation debug_id when logging an unexpected data version David Howells 2021-01-25 21:33 ` [PATCH 15/32] afs: Move key to afs_read struct David Howells 2021-01-25 21:34 ` [PATCH 16/32] afs: Don't truncate iter during data fetch David Howells 2021-01-25 21:34 ` [PATCH 17/32] afs: Log remote unmarshalling errors David Howells 2021-01-25 21:34 ` [PATCH 18/32] afs: Set up the iov_iter before calling afs_extract_data() David Howells 2021-01-25 21:34 ` [PATCH 19/32] afs: Use ITER_XARRAY for writing David Howells 2021-01-25 21:34 ` [PATCH 20/32] afs: Wait on PG_fscache before modifying/releasing a page David Howells 2021-01-25 21:35 ` [PATCH 21/32] afs: Extract writeback extension into its own function David Howells 2021-01-25 21:35 ` [PATCH 22/32] afs: Prepare for use of THPs David Howells 2021-01-25 21:35 ` [PATCH 23/32] afs: Use the fs operation ops to handle FetchData completion David Howells 2021-01-25 21:35 ` [PATCH 24/32] afs: Use new fscache read helper API David Howells 2021-01-25 21:35 ` [PATCH 25/32] NFS: Clean up nfs_readpage() and nfs_readpages() David Howells 2021-01-26 3:59 ` Matthew Wilcox 2021-01-26 15:33 ` David Wysochanski 2021-01-25 21:36 ` [PATCH 26/32] NFS: In nfs_readpage() only increment NFSIOS_READPAGES when read succeeds David Howells 2021-01-25 21:36 ` [PATCH 27/32] NFS: Refactor nfs_readpage() and nfs_readpage_async() to use nfs_readdesc David Howells 2021-01-26 4:05 ` Matthew Wilcox 2021-01-26 15:24 ` David Wysochanski 2021-01-25 21:36 ` [PATCH 28/32] NFS: Call readpage_async_filler() from nfs_readpage_async() David Howells 2021-01-25 21:36 ` [PATCH 29/32] NFS: Add nfs_pageio_complete_read() and remove nfs_readpage_async() David Howells 2021-01-25 21:37 ` [PATCH 30/32] NFS: Allow internal use of read structs and functions David Howells 2021-01-25 21:37 ` [PATCH 31/32] NFS: Convert to the netfs API and nfs_readpage to use netfs_readpage David Howells 2021-01-25 21:37 ` [PATCH 32/32] NFS: Convert readpage to readahead and use netfs_readahead for fscache David Howells 2021-01-26 1:36 ` Matthew Wilcox 2021-01-26 15:24 ` Chuck Lever 2021-01-26 19:10 ` David Wysochanski 2021-01-26 18:25 ` David Wysochanski
Reply instructions: You may reply publicly to this message via plain-text email using any one of the following methods: * Save the following mbox file, import it into your mail client, and reply-to-all from there: mbox Avoid top-posting and favor interleaved quoting: https://en.wikipedia.org/wiki/Posting_style#Interleaved_style * Reply using the --to, --cc, and --in-reply-to switches of git-send-email(1): git send-email \ --in-reply-to=161161033468.2537118.14021843889844001905.stgit@warthog.procyon.org.uk \ --to=dhowells@redhat.com \ --cc=anna.schumaker@netapp.com \ --cc=asmadeus@codewreck.org \ --cc=ceph-devel@vger.kernel.org \ --cc=dwysocha@redhat.com \ --cc=jlayton@redhat.com \ --cc=linux-afs@lists.infradead.org \ --cc=linux-cachefs@redhat.com \ --cc=linux-cifs@vger.kernel.org \ --cc=linux-fsdevel@vger.kernel.org \ --cc=linux-kernel@vger.kernel.org \ --cc=linux-nfs@vger.kernel.org \ --cc=sfrench@samba.org \ --cc=trondmy@hammerspace.com \ --cc=v9fs-developer@lists.sourceforge.net \ --cc=viro@zeniv.linux.org.uk \ --cc=willy@infradead.org \ /path/to/YOUR_REPLY https://kernel.org/pub/software/scm/git/docs/git-send-email.html * If your mail client supports setting the In-Reply-To header via mailto: links, try the mailto: link
CEPH-Devel Archive on lore.kernel.org Archives are clonable: git clone --mirror https://lore.kernel.org/ceph-devel/0 ceph-devel/git/0.git # If you have public-inbox 1.1+ installed, you may # initialize and index your mirror using the following commands: public-inbox-init -V2 ceph-devel ceph-devel/ https://lore.kernel.org/ceph-devel \ ceph-devel@vger.kernel.org public-inbox-index ceph-devel Example config snippet for mirrors Newsgroup available over NNTP: nntp://nntp.lore.kernel.org/org.kernel.vger.ceph-devel AGPL code for this site: git clone https://public-inbox.org/public-inbox.git