These apply on top of Jeff's reference counting update.
---
Chuck Lever (2):
NFSD: Add an nfsd_file_fsync tracepoint
NFSD: Re-arrange file_close_inode tracepoints
fs/nfsd/filecache.c | 22 ++++++-------
fs/nfsd/trace.h | 76 ++++++++++++++++++++++++++++-----------------
2 files changed, 57 insertions(+), 41 deletions(-)
--
Chuck Lever
Add a tracepoint to capture the number of filecache-triggered fsync
calls and which files needed it. Also, record when an fsync might
trigger a write verifier reset.
Examples:
<...>-97 [007] 262.505611: nfsd_file_free: inode=0xffff888171e08140 ref=0 flags=GC may=WRITE nf_file=0xffff8881373d2400
<...>-97 [007] 262.505612: nfsd_file_fsync: inode=0xffff888171e08140 ref=0 flags=GC may=WRITE nf_file=0xffff8881373d2400 ret=0
<...>-97 [007] 262.505623: nfsd_file_free: inode=0xffff888171e08dc0 ref=0 flags=GC may=WRITE nf_file=0xffff8881373d1e00
<...>-97 [007] 262.505624: nfsd_file_fsync: inode=0xffff888171e08dc0 ref=0 flags=GC may=WRITE nf_file=0xffff8881373d1e00 ret=0
Signed-off-by: Chuck Lever <[email protected]>
---
fs/nfsd/filecache.c | 5 ++++-
fs/nfsd/trace.h | 31 +++++++++++++++++++++++++++++++
2 files changed, 35 insertions(+), 1 deletion(-)
diff --git a/fs/nfsd/filecache.c b/fs/nfsd/filecache.c
index 19af18d386a2..cf1a8f1d1349 100644
--- a/fs/nfsd/filecache.c
+++ b/fs/nfsd/filecache.c
@@ -334,10 +334,13 @@ static void
nfsd_file_fsync(struct nfsd_file *nf)
{
struct file *file = nf->nf_file;
+ int ret;
if (!file || !(file->f_mode & FMODE_WRITE))
return;
- if (vfs_fsync(file, 1) != 0)
+ ret = vfs_fsync(file, 1);
+ trace_nfsd_file_fsync(nf, ret);
+ if (ret)
nfsd_reset_write_verifier(net_generic(nf->nf_net, nfsd_net_id));
}
diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
index 736a99448d66..e41007807b7e 100644
--- a/fs/nfsd/trace.h
+++ b/fs/nfsd/trace.h
@@ -1238,6 +1238,37 @@ DEFINE_EVENT(nfsd_file_lruwalk_class, name, \
DEFINE_NFSD_FILE_LRUWALK_EVENT(nfsd_file_gc_removed);
DEFINE_NFSD_FILE_LRUWALK_EVENT(nfsd_file_shrinker_removed);
+TRACE_EVENT(nfsd_file_fsync,
+ TP_PROTO(
+ const struct nfsd_file *nf,
+ int ret
+ ),
+ TP_ARGS(nf,ret),
+ TP_STRUCT__entry(
+ __field(void *, nf_inode)
+ __field(int, nf_ref)
+ __field(int, ret)
+ __field(unsigned long, nf_flags)
+ __field(unsigned char, nf_may)
+ __field(struct file *, nf_file)
+ ),
+ TP_fast_assign(
+ __entry->nf_inode = nf->nf_inode;
+ __entry->nf_ref = refcount_read(&nf->nf_ref);
+ __entry->ret = ret;
+ __entry->nf_flags = nf->nf_flags;
+ __entry->nf_may = nf->nf_may;
+ __entry->nf_file = nf->nf_file;
+ ),
+ TP_printk("inode=%p ref=%d flags=%s may=%s nf_file=%p ret=%d",
+ __entry->nf_inode,
+ __entry->nf_ref,
+ show_nf_flags(__entry->nf_flags),
+ show_nfsd_may_flags(__entry->nf_may),
+ __entry->nf_file, __entry->ret
+ )
+);
+
#include "cache.h"
TRACE_DEFINE_ENUM(RC_DROPIT);
Now that we have trace_nfsd_file_closing, all we really need to
capture is when an external caller has requested a close/sync.
Signed-off-by: Chuck Lever <[email protected]>
---
fs/nfsd/filecache.c | 17 ++++++-----------
fs/nfsd/trace.h | 45 ++++++++++++++++-----------------------------
2 files changed, 22 insertions(+), 40 deletions(-)
diff --git a/fs/nfsd/filecache.c b/fs/nfsd/filecache.c
index cf1a8f1d1349..7be62af4bfb7 100644
--- a/fs/nfsd/filecache.c
+++ b/fs/nfsd/filecache.c
@@ -706,14 +706,13 @@ static struct shrinker nfsd_file_shrinker = {
* The nfsd_file objects on the list will be unhashed, and each will have a
* reference taken.
*/
-static unsigned int
+static void
__nfsd_file_close_inode(struct inode *inode, struct list_head *dispose)
{
struct nfsd_file_lookup_key key = {
.type = NFSD_FILE_KEY_INODE,
.inode = inode,
};
- unsigned int count = 0;
struct nfsd_file *nf;
rcu_read_lock();
@@ -723,11 +722,9 @@ __nfsd_file_close_inode(struct inode *inode, struct list_head *dispose)
if (!nf)
break;
- if (nfsd_file_unhash_and_queue(nf, dispose))
- count++;
+ nfsd_file_unhash_and_queue(nf, dispose);
} while (1);
rcu_read_unlock();
- return count;
}
/**
@@ -742,11 +739,9 @@ static void
nfsd_file_close_inode(struct inode *inode)
{
struct nfsd_file *nf, *tmp;
- unsigned int count;
LIST_HEAD(dispose);
- count = __nfsd_file_close_inode(inode, &dispose);
- trace_nfsd_file_close_inode(inode, count);
+ __nfsd_file_close_inode(inode, &dispose);
list_for_each_entry_safe(nf, tmp, &dispose, nf_lru) {
trace_nfsd_file_closing(nf);
if (!refcount_dec_and_test(&nf->nf_ref))
@@ -765,11 +760,11 @@ void
nfsd_file_close_inode_sync(struct inode *inode)
{
struct nfsd_file *nf;
- unsigned int count;
LIST_HEAD(dispose);
- count = __nfsd_file_close_inode(inode, &dispose);
- trace_nfsd_file_close_inode(inode, count);
+ trace_nfsd_file_close(inode);
+
+ __nfsd_file_close_inode(inode, &dispose);
while (!list_empty(&dispose)) {
nf = list_first_entry(&dispose, struct nfsd_file, nf_lru);
list_del_init(&nf->nf_lru);
diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
index e41007807b7e..ef01ecd3eec6 100644
--- a/fs/nfsd/trace.h
+++ b/fs/nfsd/trace.h
@@ -1099,35 +1099,6 @@ TRACE_EVENT(nfsd_file_open,
__entry->nf_file)
)
-DECLARE_EVENT_CLASS(nfsd_file_search_class,
- TP_PROTO(
- const struct inode *inode,
- unsigned int count
- ),
- TP_ARGS(inode, count),
- TP_STRUCT__entry(
- __field(const struct inode *, inode)
- __field(unsigned int, count)
- ),
- TP_fast_assign(
- __entry->inode = inode;
- __entry->count = count;
- ),
- TP_printk("inode=%p count=%u",
- __entry->inode, __entry->count)
-);
-
-#define DEFINE_NFSD_FILE_SEARCH_EVENT(name) \
-DEFINE_EVENT(nfsd_file_search_class, name, \
- TP_PROTO( \
- const struct inode *inode, \
- unsigned int count \
- ), \
- TP_ARGS(inode, count))
-
-DEFINE_NFSD_FILE_SEARCH_EVENT(nfsd_file_close_inode_sync);
-DEFINE_NFSD_FILE_SEARCH_EVENT(nfsd_file_close_inode);
-
TRACE_EVENT(nfsd_file_is_cached,
TP_PROTO(
const struct inode *inode,
@@ -1238,6 +1209,22 @@ DEFINE_EVENT(nfsd_file_lruwalk_class, name, \
DEFINE_NFSD_FILE_LRUWALK_EVENT(nfsd_file_gc_removed);
DEFINE_NFSD_FILE_LRUWALK_EVENT(nfsd_file_shrinker_removed);
+TRACE_EVENT(nfsd_file_close,
+ TP_PROTO(
+ const struct inode *inode
+ ),
+ TP_ARGS(inode),
+ TP_STRUCT__entry(
+ __field(const void *, inode)
+ ),
+ TP_fast_assign(
+ __entry->inode = inode;
+ ),
+ TP_printk("inode=%p",
+ __entry->inode
+ )
+);
+
TRACE_EVENT(nfsd_file_fsync,
TP_PROTO(
const struct nfsd_file *nf,
On Thu, 2022-11-03 at 16:22 -0400, Chuck Lever wrote:
> These apply on top of Jeff's reference counting update.
>
> ---
>
> Chuck Lever (2):
> NFSD: Add an nfsd_file_fsync tracepoint
> NFSD: Re-arrange file_close_inode tracepoints
>
>
> fs/nfsd/filecache.c | 22 ++++++-------
> fs/nfsd/trace.h | 76 ++++++++++++++++++++++++++++-----------------
> 2 files changed, 57 insertions(+), 41 deletions(-)
>
> --
> Chuck Lever
>
These look fine to me.
Reviewed-by: Jeff Layton <[email protected]>
On Thu, 2022-11-03 at 16:22 -0400, Chuck Lever wrote:
> Now that we have trace_nfsd_file_closing, all we really need to
> capture is when an external caller has requested a close/sync.
>
> Signed-off-by: Chuck Lever <[email protected]>
> ---
> fs/nfsd/filecache.c | 17 ++++++-----------
> fs/nfsd/trace.h | 45 ++++++++++++++++-----------------------------
> 2 files changed, 22 insertions(+), 40 deletions(-)
>
> diff --git a/fs/nfsd/filecache.c b/fs/nfsd/filecache.c
> index cf1a8f1d1349..7be62af4bfb7 100644
> --- a/fs/nfsd/filecache.c
> +++ b/fs/nfsd/filecache.c
> @@ -706,14 +706,13 @@ static struct shrinker nfsd_file_shrinker = {
> * The nfsd_file objects on the list will be unhashed, and each will have a
> * reference taken.
> */
> -static unsigned int
> +static void
> __nfsd_file_close_inode(struct inode *inode, struct list_head *dispose)
> {
> struct nfsd_file_lookup_key key = {
> .type = NFSD_FILE_KEY_INODE,
> .inode = inode,
> };
> - unsigned int count = 0;
> struct nfsd_file *nf;
>
> rcu_read_lock();
> @@ -723,11 +722,9 @@ __nfsd_file_close_inode(struct inode *inode, struct list_head *dispose)
> if (!nf)
> break;
>
> - if (nfsd_file_unhash_and_queue(nf, dispose))
> - count++;
> + nfsd_file_unhash_and_queue(nf, dispose);
> } while (1);
> rcu_read_unlock();
> - return count;
> }
>
> /**
> @@ -742,11 +739,9 @@ static void
> nfsd_file_close_inode(struct inode *inode)
> {
> struct nfsd_file *nf, *tmp;
> - unsigned int count;
> LIST_HEAD(dispose);
>
> - count = __nfsd_file_close_inode(inode, &dispose);
> - trace_nfsd_file_close_inode(inode, count);
> + __nfsd_file_close_inode(inode, &dispose);
> list_for_each_entry_safe(nf, tmp, &dispose, nf_lru) {
> trace_nfsd_file_closing(nf);
> if (!refcount_dec_and_test(&nf->nf_ref))
> @@ -765,11 +760,11 @@ void
> nfsd_file_close_inode_sync(struct inode *inode)
> {
> struct nfsd_file *nf;
> - unsigned int count;
> LIST_HEAD(dispose);
>
> - count = __nfsd_file_close_inode(inode, &dispose);
> - trace_nfsd_file_close_inode(inode, count);
> + trace_nfsd_file_close(inode);
With this change we lose the count of entries on the list. That info is
not particularly helpful, but maybe we ought to consider a tracepoint in
unhash_and_queue that records whether a file we found in the hash got
queued? It might be nice to have a way to detect cases where we close a
nfsd_file but the refcount was >1 or 0, so we don't end up queueing it
to the list.
> +
> + __nfsd_file_close_inode(inode, &dispose);
> while (!list_empty(&dispose)) {
> nf = list_first_entry(&dispose, struct nfsd_file, nf_lru);
> list_del_init(&nf->nf_lru);
> diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
> index e41007807b7e..ef01ecd3eec6 100644
> --- a/fs/nfsd/trace.h
> +++ b/fs/nfsd/trace.h
> @@ -1099,35 +1099,6 @@ TRACE_EVENT(nfsd_file_open,
> __entry->nf_file)
> )
>
> -DECLARE_EVENT_CLASS(nfsd_file_search_class,
> - TP_PROTO(
> - const struct inode *inode,
> - unsigned int count
> - ),
> - TP_ARGS(inode, count),
> - TP_STRUCT__entry(
> - __field(const struct inode *, inode)
> - __field(unsigned int, count)
> - ),
> - TP_fast_assign(
> - __entry->inode = inode;
> - __entry->count = count;
> - ),
> - TP_printk("inode=%p count=%u",
> - __entry->inode, __entry->count)
> -);
> -
> -#define DEFINE_NFSD_FILE_SEARCH_EVENT(name) \
> -DEFINE_EVENT(nfsd_file_search_class, name, \
> - TP_PROTO( \
> - const struct inode *inode, \
> - unsigned int count \
> - ), \
> - TP_ARGS(inode, count))
> -
> -DEFINE_NFSD_FILE_SEARCH_EVENT(nfsd_file_close_inode_sync);
> -DEFINE_NFSD_FILE_SEARCH_EVENT(nfsd_file_close_inode);
> -
> TRACE_EVENT(nfsd_file_is_cached,
> TP_PROTO(
> const struct inode *inode,
> @@ -1238,6 +1209,22 @@ DEFINE_EVENT(nfsd_file_lruwalk_class, name, \
> DEFINE_NFSD_FILE_LRUWALK_EVENT(nfsd_file_gc_removed);
> DEFINE_NFSD_FILE_LRUWALK_EVENT(nfsd_file_shrinker_removed);
>
> +TRACE_EVENT(nfsd_file_close,
> + TP_PROTO(
> + const struct inode *inode
> + ),
> + TP_ARGS(inode),
> + TP_STRUCT__entry(
> + __field(const void *, inode)
> + ),
> + TP_fast_assign(
> + __entry->inode = inode;
> + ),
> + TP_printk("inode=%p",
> + __entry->inode
> + )
> +);
> +
> TRACE_EVENT(nfsd_file_fsync,
> TP_PROTO(
> const struct nfsd_file *nf,
>
>
--
Jeff Layton <[email protected]>
> On Nov 4, 2022, at 8:44 AM, Jeff Layton <[email protected]> wrote:
>
> On Thu, 2022-11-03 at 16:22 -0400, Chuck Lever wrote:
>> Now that we have trace_nfsd_file_closing, all we really need to
>> capture is when an external caller has requested a close/sync.
>>
>> Signed-off-by: Chuck Lever <[email protected]>
>> ---
>> fs/nfsd/filecache.c | 17 ++++++-----------
>> fs/nfsd/trace.h | 45 ++++++++++++++++-----------------------------
>> 2 files changed, 22 insertions(+), 40 deletions(-)
>>
>> diff --git a/fs/nfsd/filecache.c b/fs/nfsd/filecache.c
>> index cf1a8f1d1349..7be62af4bfb7 100644
>> --- a/fs/nfsd/filecache.c
>> +++ b/fs/nfsd/filecache.c
>> @@ -706,14 +706,13 @@ static struct shrinker nfsd_file_shrinker = {
>> * The nfsd_file objects on the list will be unhashed, and each will have a
>> * reference taken.
>> */
>> -static unsigned int
>> +static void
>> __nfsd_file_close_inode(struct inode *inode, struct list_head *dispose)
>> {
>> struct nfsd_file_lookup_key key = {
>> .type = NFSD_FILE_KEY_INODE,
>> .inode = inode,
>> };
>> - unsigned int count = 0;
>> struct nfsd_file *nf;
>>
>> rcu_read_lock();
>> @@ -723,11 +722,9 @@ __nfsd_file_close_inode(struct inode *inode, struct list_head *dispose)
>> if (!nf)
>> break;
>>
>> - if (nfsd_file_unhash_and_queue(nf, dispose))
>> - count++;
>> + nfsd_file_unhash_and_queue(nf, dispose);
>> } while (1);
>> rcu_read_unlock();
>> - return count;
>> }
>>
>> /**
>> @@ -742,11 +739,9 @@ static void
>> nfsd_file_close_inode(struct inode *inode)
>> {
>> struct nfsd_file *nf, *tmp;
>> - unsigned int count;
>> LIST_HEAD(dispose);
>>
>> - count = __nfsd_file_close_inode(inode, &dispose);
>> - trace_nfsd_file_close_inode(inode, count);
>> + __nfsd_file_close_inode(inode, &dispose);
>> list_for_each_entry_safe(nf, tmp, &dispose, nf_lru) {
>> trace_nfsd_file_closing(nf);
>> if (!refcount_dec_and_test(&nf->nf_ref))
>> @@ -765,11 +760,11 @@ void
>> nfsd_file_close_inode_sync(struct inode *inode)
>> {
>> struct nfsd_file *nf;
>> - unsigned int count;
>> LIST_HEAD(dispose);
>>
>> - count = __nfsd_file_close_inode(inode, &dispose);
>> - trace_nfsd_file_close_inode(inode, count);
>> + trace_nfsd_file_close(inode);
>
> With this change we lose the count of entries on the list. That info is
> not particularly helpful, but maybe we ought to consider a tracepoint in
> unhash_and_queue that records whether a file we found in the hash got
> queued? It might be nice to have a way to detect cases where we close a
> nfsd_file but the refcount was >1 or 0, so we don't end up queueing it
> to the list.
Would that be an exception case, or an error? I'm assuming the former.
No objection if you'd like to add that as part of a follow-on series.
>> +
>> + __nfsd_file_close_inode(inode, &dispose);
>> while (!list_empty(&dispose)) {
>> nf = list_first_entry(&dispose, struct nfsd_file, nf_lru);
>> list_del_init(&nf->nf_lru);
>> diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
>> index e41007807b7e..ef01ecd3eec6 100644
>> --- a/fs/nfsd/trace.h
>> +++ b/fs/nfsd/trace.h
>> @@ -1099,35 +1099,6 @@ TRACE_EVENT(nfsd_file_open,
>> __entry->nf_file)
>> )
>>
>> -DECLARE_EVENT_CLASS(nfsd_file_search_class,
>> - TP_PROTO(
>> - const struct inode *inode,
>> - unsigned int count
>> - ),
>> - TP_ARGS(inode, count),
>> - TP_STRUCT__entry(
>> - __field(const struct inode *, inode)
>> - __field(unsigned int, count)
>> - ),
>> - TP_fast_assign(
>> - __entry->inode = inode;
>> - __entry->count = count;
>> - ),
>> - TP_printk("inode=%p count=%u",
>> - __entry->inode, __entry->count)
>> -);
>> -
>> -#define DEFINE_NFSD_FILE_SEARCH_EVENT(name) \
>> -DEFINE_EVENT(nfsd_file_search_class, name, \
>> - TP_PROTO( \
>> - const struct inode *inode, \
>> - unsigned int count \
>> - ), \
>> - TP_ARGS(inode, count))
>> -
>> -DEFINE_NFSD_FILE_SEARCH_EVENT(nfsd_file_close_inode_sync);
>> -DEFINE_NFSD_FILE_SEARCH_EVENT(nfsd_file_close_inode);
>> -
>> TRACE_EVENT(nfsd_file_is_cached,
>> TP_PROTO(
>> const struct inode *inode,
>> @@ -1238,6 +1209,22 @@ DEFINE_EVENT(nfsd_file_lruwalk_class, name, \
>> DEFINE_NFSD_FILE_LRUWALK_EVENT(nfsd_file_gc_removed);
>> DEFINE_NFSD_FILE_LRUWALK_EVENT(nfsd_file_shrinker_removed);
>>
>> +TRACE_EVENT(nfsd_file_close,
>> + TP_PROTO(
>> + const struct inode *inode
>> + ),
>> + TP_ARGS(inode),
>> + TP_STRUCT__entry(
>> + __field(const void *, inode)
>> + ),
>> + TP_fast_assign(
>> + __entry->inode = inode;
>> + ),
>> + TP_printk("inode=%p",
>> + __entry->inode
>> + )
>> +);
>> +
>> TRACE_EVENT(nfsd_file_fsync,
>> TP_PROTO(
>> const struct nfsd_file *nf,
>>
>>
>
> --
> Jeff Layton <[email protected]>
--
Chuck Lever