2021-03-12 11:52:12

by Paul Menzel

[permalink] [raw]
Subject: [PATCH] nfsd: Demote UMH upcall init message from warning- to info-level

By default, using `printk()`, Linux logs messages with level warning,
which leaves the user seeing

NFSD: Using UMH upcall client tracking operations.

what to do about it. Reading `nfsd4_umh_cltrack_init()`, the message is
actually logged on success, so nothing needs to be done, and the info
level should be used.

Cc: [email protected]
Signed-off-by: Paul Menzel <[email protected]>
---
fs/nfsd/nfs4recover.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/fs/nfsd/nfs4recover.c b/fs/nfsd/nfs4recover.c
index 891395c6c7d3..db66c45a6b97 100644
--- a/fs/nfsd/nfs4recover.c
+++ b/fs/nfsd/nfs4recover.c
@@ -1864,7 +1864,7 @@ nfsd4_umh_cltrack_init(struct net *net)
ret = nfsd4_umh_cltrack_upcall("init", NULL, grace_start, NULL);
kfree(grace_start);
if (!ret)
- printk("NFSD: Using UMH upcall client tracking operations.\n");
+ pr_info("NFSD: Using UMH upcall client tracking operations.\n");
return ret;
}

--
2.30.2


2021-03-12 11:52:13

by Paul Menzel

[permalink] [raw]
Subject: Re: [PATCH] nfsd: Demote UMH upcall init message from warning- to info-level

Dear Linux folks,


Am 12.03.21 um 12:28 schrieb Paul Menzel:
> By default, using `printk()`, Linux logs messages with level warning,
> which leaves the user seeing
>
> NFSD: Using UMH upcall client tracking operations.
>
> what to do about it. Reading `nfsd4_umh_cltrack_init()`, the message is
> actually logged on success, so nothing needs to be done, and the info
> level should be used.
>
> Cc: [email protected]
> Signed-off-by: Paul Menzel <[email protected]>
> ---
> fs/nfsd/nfs4recover.c | 2 +-
> 1 file changed, 1 insertion(+), 1 deletion(-)
>
> diff --git a/fs/nfsd/nfs4recover.c b/fs/nfsd/nfs4recover.c
> index 891395c6c7d3..db66c45a6b97 100644
> --- a/fs/nfsd/nfs4recover.c
> +++ b/fs/nfsd/nfs4recover.c
> @@ -1864,7 +1864,7 @@ nfsd4_umh_cltrack_init(struct net *net)
> ret = nfsd4_umh_cltrack_upcall("init", NULL, grace_start, NULL);
> kfree(grace_start);
> if (!ret)
> - printk("NFSD: Using UMH upcall client tracking operations.\n");
> + pr_info("NFSD: Using UMH upcall client tracking operations.\n");
> return ret;
> }

A debug-level message could also be used, or the line totally removed,
and the condition be changed to print an error in case of failure. I am
wondering about the benefit for the user reading through the logs. Maybe
the log was only there, because UMH upcall client tracking operations
were something new?


Kind regards,

Paul

2021-03-12 15:34:24

by J. Bruce Fields

[permalink] [raw]
Subject: Re: [PATCH] nfsd: Demote UMH upcall init message from warning- to info-level

On Fri, Mar 12, 2021 at 12:33:00PM +0100, Paul Menzel wrote:
> Dear Linux folks,
>
>
> Am 12.03.21 um 12:28 schrieb Paul Menzel:
> >By default, using `printk()`, Linux logs messages with level warning,
> >which leaves the user seeing
> >
> > NFSD: Using UMH upcall client tracking operations.
> >
> >what to do about it. Reading `nfsd4_umh_cltrack_init()`, the message is
> >actually logged on success, so nothing needs to be done, and the info
> >level should be used.
> >
> >Cc: [email protected]
> >Signed-off-by: Paul Menzel <[email protected]>
> >---
> > fs/nfsd/nfs4recover.c | 2 +-
> > 1 file changed, 1 insertion(+), 1 deletion(-)
> >
> >diff --git a/fs/nfsd/nfs4recover.c b/fs/nfsd/nfs4recover.c
> >index 891395c6c7d3..db66c45a6b97 100644
> >--- a/fs/nfsd/nfs4recover.c
> >+++ b/fs/nfsd/nfs4recover.c
> >@@ -1864,7 +1864,7 @@ nfsd4_umh_cltrack_init(struct net *net)
> > ret = nfsd4_umh_cltrack_upcall("init", NULL, grace_start, NULL);
> > kfree(grace_start);
> > if (!ret)
> >- printk("NFSD: Using UMH upcall client tracking operations.\n");
> >+ pr_info("NFSD: Using UMH upcall client tracking operations.\n");
> > return ret;
> > }
>
> A debug-level message could also be used, or the line totally
> removed, and the condition be changed to print an error in case of
> failure. I am wondering about the benefit for the user reading
> through the logs. Maybe the log was only there, because UMH upcall
> client tracking operations were something new?

Could be.

I think debug-level would be fine.

--b.

2021-03-12 17:07:34

by Paul Menzel

[permalink] [raw]
Subject: [PATCH v2] nfsd: Log error on UMH upcall init failure and debug message on success

By default, using `printk()`, Linux logs messages with level warning,
which leaves the user reading

NFSD: Using UMH upcall client tracking operations.

wondering what to do about it. Reading `nfsd4_umh_cltrack_init()`, the
message is actually logged on success, so nothing needs to be done, and
it was decided to use the debug level.

Additionally, Linux now logs an error on init failure.

NFSD: Failed to init UMH upcall client tracking operations.

Cc: [email protected]
Signed-off-by: Paul Menzel <[email protected]>
---
fs/nfsd/nfs4recover.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/fs/nfsd/nfs4recover.c b/fs/nfsd/nfs4recover.c
index 891395c6c7d3..db66c45a6b97 100644
--- a/fs/nfsd/nfs4recover.c
+++ b/fs/nfsd/nfs4recover.c
@@ -1864,7 +1864,7 @@ nfsd4_umh_cltrack_init(struct net *net)
ret = nfsd4_umh_cltrack_upcall("init", NULL, grace_start, NULL);
kfree(grace_start);
if (!ret)
- printk("NFSD: Using UMH upcall client tracking operations.\n");
+ pr_info("NFSD: Using UMH upcall client tracking operations.\n");
return ret;
}

--
2.30.2

2021-03-12 17:11:06

by Paul Menzel

[permalink] [raw]
Subject: [PATCH v3] nfsd: Log error on UMH upcall init failure and debug message on success

By default, using `printk()`, Linux logs messages with level warning,
which leaves the user reading

NFSD: Using UMH upcall client tracking operations.

wondering what to do about it. Reading `nfsd4_umh_cltrack_init()`, the
message is actually logged on success, so nothing needs to be done, and
it was decided to use the debug level.

Additionally, Linux now logs an error on init failure.

NFSD: Failed to init UMH upcall client tracking operations.

Cc: [email protected]
Signed-off-by: Paul Menzel <[email protected]>
---
v2: Log error and demote success message to debug-level (forgot `-a` in `git commit --amend`)
v3: Actually sent correct diff

fs/nfsd/nfs4recover.c | 7 +++++--
1 file changed, 5 insertions(+), 2 deletions(-)

diff --git a/fs/nfsd/nfs4recover.c b/fs/nfsd/nfs4recover.c
index 891395c6c7d3..fff89c739033 100644
--- a/fs/nfsd/nfs4recover.c
+++ b/fs/nfsd/nfs4recover.c
@@ -1863,8 +1863,11 @@ nfsd4_umh_cltrack_init(struct net *net)

ret = nfsd4_umh_cltrack_upcall("init", NULL, grace_start, NULL);
kfree(grace_start);
- if (!ret)
- printk("NFSD: Using UMH upcall client tracking operations.\n");
+ if (ret)
+ pr_debug("NFSD: Using UMH upcall client tracking operations.\n");
+ else
+ pr_err("NFSD: Failed to init UMH upcall client tracking operations.");
+
return ret;
}

--
2.30.2

2021-03-12 19:08:40

by J. Bruce Fields

[permalink] [raw]
Subject: Re: [PATCH v3] nfsd: Log error on UMH upcall init failure and debug message on success

On Fri, Mar 12, 2021 at 06:09:44PM +0100, Paul Menzel wrote:
> By default, using `printk()`, Linux logs messages with level warning,
> which leaves the user reading
>
> NFSD: Using UMH upcall client tracking operations.
>
> wondering what to do about it. Reading `nfsd4_umh_cltrack_init()`, the
> message is actually logged on success, so nothing needs to be done, and
> it was decided to use the debug level.
>
> Additionally, Linux now logs an error on init failure.
>
> NFSD: Failed to init UMH upcall client tracking operations.

The thing is, it's actually trying a series of different mechanisms (see
nfsd4_client_tracking_init) and taking the first one that works. It's
more useful to see which one of them ends up being chosen rather than
the list of mechanisms that failed. (And those failures are normal if
userland is configured to use something lower down in the list.)

So, let's just demote to "debug" and leave the logic otherwise
unchanged.

--b.

>
> Cc: [email protected]
> Signed-off-by: Paul Menzel <[email protected]>
> ---
> v2: Log error and demote success message to debug-level (forgot `-a` in `git commit --amend`)
> v3: Actually sent correct diff
>
> fs/nfsd/nfs4recover.c | 7 +++++--
> 1 file changed, 5 insertions(+), 2 deletions(-)
>
> diff --git a/fs/nfsd/nfs4recover.c b/fs/nfsd/nfs4recover.c
> index 891395c6c7d3..fff89c739033 100644
> --- a/fs/nfsd/nfs4recover.c
> +++ b/fs/nfsd/nfs4recover.c
> @@ -1863,8 +1863,11 @@ nfsd4_umh_cltrack_init(struct net *net)
>
> ret = nfsd4_umh_cltrack_upcall("init", NULL, grace_start, NULL);
> kfree(grace_start);
> - if (!ret)
> - printk("NFSD: Using UMH upcall client tracking operations.\n");
> + if (ret)
> + pr_debug("NFSD: Using UMH upcall client tracking operations.\n");
> + else
> + pr_err("NFSD: Failed to init UMH upcall client tracking operations.");
> +
> return ret;
> }
>
> --
> 2.30.2

2021-03-12 19:55:00

by Chuck Lever III

[permalink] [raw]
Subject: Re: [PATCH v3] nfsd: Log error on UMH upcall init failure and debug message on success

Hi Paul-

> On Mar 12, 2021, at 12:09 PM, Paul Menzel <[email protected]> wrote:
>
> By default, using `printk()`, Linux logs messages with level warning,
> which leaves the user reading
>
> NFSD: Using UMH upcall client tracking operations.
>
> wondering what to do about it. Reading `nfsd4_umh_cltrack_init()`, the
> message is actually logged on success, so nothing needs to be done, and
> it was decided to use the debug level.
>
> Additionally, Linux now logs an error on init failure.
>
> NFSD: Failed to init UMH upcall client tracking operations.
>
> Cc: [email protected]
> Signed-off-by: Paul Menzel <[email protected]>
> ---
> v2: Log error and demote success message to debug-level (forgot `-a` in `git commit --amend`)
> v3: Actually sent correct diff
>
> fs/nfsd/nfs4recover.c | 7 +++++--
> 1 file changed, 5 insertions(+), 2 deletions(-)
>
> diff --git a/fs/nfsd/nfs4recover.c b/fs/nfsd/nfs4recover.c
> index 891395c6c7d3..fff89c739033 100644
> --- a/fs/nfsd/nfs4recover.c
> +++ b/fs/nfsd/nfs4recover.c
> @@ -1863,8 +1863,11 @@ nfsd4_umh_cltrack_init(struct net *net)
>
> ret = nfsd4_umh_cltrack_upcall("init", NULL, grace_start, NULL);
> kfree(grace_start);
> - if (!ret)
> - printk("NFSD: Using UMH upcall client tracking operations.\n");
> + if (ret)
> + pr_debug("NFSD: Using UMH upcall client tracking operations.\n");

Looking back at 869216075b63 ("nfsd: re-order client tracking method selection"),
the idea here seems to be that only one of the "Using yada upcall client" is
supposed to fire. If an error occurs here, there is a fallback. No additional
error need be reported, IMHO.

So the printk() call-sites added by 869216075b63 all need to be adjusted to use
pr_info(), I think?


> + else
> + pr_err("NFSD: Failed to init UMH upcall client tracking operations.");
> +
> return ret;
> }
>
> --
> 2.30.2
>

--
Chuck Lever



2021-03-12 21:05:56

by Paul Menzel

[permalink] [raw]
Subject: [PATCH v4] nfsd: Log client tracking type log message as info instead of warning

`printk()`, by default, uses the log level warning, which leaves the
user reading

NFSD: Using UMH upcall client tracking operations.

wondering what to do about it (`dmesg --level=warn`).

Several client tracking methods are tried, and expected to fail. That’s
why a message is printed only on success. It might be interesting for
users to know the chosen method, so use info-level instead of
debug-level.

Cc: [email protected]
Signed-off-by: Paul Menzel <[email protected]>
---
v4: Remove error message, and use info-level, as several client tracking
methods are tried.

fs/nfsd/nfs4recover.c | 8 ++++----
1 file changed, 4 insertions(+), 4 deletions(-)

diff --git a/fs/nfsd/nfs4recover.c b/fs/nfsd/nfs4recover.c
index 891395c6c7d3..6fedc49726bf 100644
--- a/fs/nfsd/nfs4recover.c
+++ b/fs/nfsd/nfs4recover.c
@@ -626,7 +626,7 @@ nfsd4_legacy_tracking_init(struct net *net)
status = nfsd4_load_reboot_recovery_data(net);
if (status)
goto err;
- printk("NFSD: Using legacy client tracking operations.\n");
+ pr_info("NFSD: Using legacy client tracking operations.\n");
return 0;

err:
@@ -1028,7 +1028,7 @@ nfsd4_init_cld_pipe(struct net *net)

status = __nfsd4_init_cld_pipe(net);
if (!status)
- printk("NFSD: Using old nfsdcld client tracking operations.\n");
+ pr_info("NFSD: Using old nfsdcld client tracking operations.\n");
return status;
}

@@ -1605,7 +1605,7 @@ nfsd4_cld_tracking_init(struct net *net)
nfs4_release_reclaim(nn);
goto err_remove;
} else
- printk("NFSD: Using nfsdcld client tracking operations.\n");
+ pr_info("NFSD: Using nfsdcld client tracking operations.\n");
return 0;

err_remove:
@@ -1864,7 +1864,7 @@ nfsd4_umh_cltrack_init(struct net *net)
ret = nfsd4_umh_cltrack_upcall("init", NULL, grace_start, NULL);
kfree(grace_start);
if (!ret)
- printk("NFSD: Using UMH upcall client tracking operations.\n");
+ pr_info("NFSD: Using UMH upcall client tracking operations.\n");
return ret;
}

--
2.30.2

2021-03-15 14:31:46

by Chuck Lever III

[permalink] [raw]
Subject: Re: [PATCH v4] nfsd: Log client tracking type log message as info instead of warning



> On Mar 12, 2021, at 4:03 PM, Paul Menzel <[email protected]> wrote:
>
> `printk()`, by default, uses the log level warning, which leaves the
> user reading
>
> NFSD: Using UMH upcall client tracking operations.
>
> wondering what to do about it (`dmesg --level=warn`).
>
> Several client tracking methods are tried, and expected to fail. That’s
> why a message is printed only on success. It might be interesting for
> users to know the chosen method, so use info-level instead of
> debug-level.
>
> Cc: [email protected]
> Signed-off-by: Paul Menzel <[email protected]>

Hi Paul, I've included your patch in the for-next topic branch at

git://git.kernel.org/pub/scm/linux/kernel/git/cel/linux.git


> ---
> v4: Remove error message, and use info-level, as several client tracking
> methods are tried.
>
> fs/nfsd/nfs4recover.c | 8 ++++----
> 1 file changed, 4 insertions(+), 4 deletions(-)
>
> diff --git a/fs/nfsd/nfs4recover.c b/fs/nfsd/nfs4recover.c
> index 891395c6c7d3..6fedc49726bf 100644
> --- a/fs/nfsd/nfs4recover.c
> +++ b/fs/nfsd/nfs4recover.c
> @@ -626,7 +626,7 @@ nfsd4_legacy_tracking_init(struct net *net)
> status = nfsd4_load_reboot_recovery_data(net);
> if (status)
> goto err;
> - printk("NFSD: Using legacy client tracking operations.\n");
> + pr_info("NFSD: Using legacy client tracking operations.\n");
> return 0;
>
> err:
> @@ -1028,7 +1028,7 @@ nfsd4_init_cld_pipe(struct net *net)
>
> status = __nfsd4_init_cld_pipe(net);
> if (!status)
> - printk("NFSD: Using old nfsdcld client tracking operations.\n");
> + pr_info("NFSD: Using old nfsdcld client tracking operations.\n");
> return status;
> }
>
> @@ -1605,7 +1605,7 @@ nfsd4_cld_tracking_init(struct net *net)
> nfs4_release_reclaim(nn);
> goto err_remove;
> } else
> - printk("NFSD: Using nfsdcld client tracking operations.\n");
> + pr_info("NFSD: Using nfsdcld client tracking operations.\n");
> return 0;
>
> err_remove:
> @@ -1864,7 +1864,7 @@ nfsd4_umh_cltrack_init(struct net *net)
> ret = nfsd4_umh_cltrack_upcall("init", NULL, grace_start, NULL);
> kfree(grace_start);
> if (!ret)
> - printk("NFSD: Using UMH upcall client tracking operations.\n");
> + pr_info("NFSD: Using UMH upcall client tracking operations.\n");
> return ret;
> }
>
> --
> 2.30.2
>

--
Chuck Lever