[PATCH RFC] vfs: always log mount API fs context messages to dmesg

[PATCH RFC] vfs: always log mount API fs context messages to dmesg

[Eric Sandeen]

As filesystems are converted to the new mount API, informational messages,
errors, and warnings are being routed through infof, errorf, and warnf
type functions provided by the mount API, which places these messages in
the log buffer associated with the filesystem context rather than
in the kernel log / dmesg.

However, userspace is not yet extracting these messages, so they are
essentially getting lost. mount(8) still refers the user to dmesg(1)
on failure.

At least for now, modify logfc() to always log these messages to dmesg
as well as to the fileystem context. This way we can continue converting
filesystems to the new mount API interfaces without worrying about losing
this information until userspace can retrieve it.

Signed-off-by: Eric Sandeen <sandeen@redhat.com>
---

A few considerations/concerns:

* viro suggested that maybe this should be conditional - possibly config

* systemd is currently probing with a dummy mount option which will
  generate noise, see
  https://github.com/systemd/systemd/blob/main/src/basic/mountpoint-util.c#L759
  i.e. - 
  [   10.689256] proc: Unknown parameter 'adefinitelynotexistingmountoption'
  [   10.801045] tmpfs: Unknown parameter 'adefinitelynotexistingmountoption'
  [   11.119431] proc: Unknown parameter 'adefinitelynotexistingmountoption'
  [   11.692032] proc: Unknown parameter 'adefinitelynotexistingmountoption'

* will this generate other dmesg noise in general if the mount api messages
  are more noisy in general? (spot-checking old conversions, I don't think so.)

 fs/fs_context.c | 38 ++++++++++++++++++++------------------
 1 file changed, 20 insertions(+), 18 deletions(-)

diff --git a/fs/fs_context.c b/fs/fs_context.c
index 98589aae5208..3c78b99d5cae 100644
--- a/fs/fs_context.c
+++ b/fs/fs_context.c
@@ -427,8 +427,8 @@ struct fs_context *vfs_dup_fs_context(struct fs_context *src_fc)
 EXPORT_SYMBOL(vfs_dup_fs_context);
 
 /**
- * logfc - Log a message to a filesystem context
- * @log: The filesystem context to log to, or NULL to use printk.
+ * logfc - Log a message to dmesg and optionally a filesystem context
+ * @log: The filesystem context to log to, or NULL to use printk alone
  * @prefix: A string to prefix the output with, or NULL.
  * @level: 'w' for a warning, 'e' for an error.  Anything else is a notice.
  * @fmt: The format of the buffer.
@@ -439,22 +439,24 @@ void logfc(struct fc_log *log, const char *prefix, char level, const char *fmt,
 	struct va_format vaf = {.fmt = fmt, .va = &va};
 
 	va_start(va, fmt);
-	if (!log) {
-		switch (level) {
-		case 'w':
-			printk(KERN_WARNING "%s%s%pV\n", prefix ? prefix : "",
-						prefix ? ": " : "", &vaf);
-			break;
-		case 'e':
-			printk(KERN_ERR "%s%s%pV\n", prefix ? prefix : "",
-						prefix ? ": " : "", &vaf);
-			break;
-		default:
-			printk(KERN_NOTICE "%s%s%pV\n", prefix ? prefix : "",
-						prefix ? ": " : "", &vaf);
-			break;
-		}
-	} else {
+	switch (level) {
+	case 'w':
+		printk(KERN_WARNING "%s%s%pV\n", prefix ? prefix : "",
+					prefix ? ": " : "", &vaf);
+		break;
+	case 'e':
+		printk(KERN_ERR "%s%s%pV\n", prefix ? prefix : "",
+					prefix ? ": " : "", &vaf);
+		break;
+	default:
+		printk(KERN_NOTICE "%s%s%pV\n", prefix ? prefix : "",
+					prefix ? ": " : "", &vaf);
+		break;
+	}
+	va_end(va);
+
+	va_start(va, fmt);
+	if (log) {
 		unsigned int logsize = ARRAY_SIZE(log->buffer);
 		u8 index;
 		char *q = kasprintf(GFP_KERNEL, "%c %s%s%pV\n", level,
-- 
2.43.0

Re: [PATCH RFC] vfs: always log mount API fs context messages to dmesg

[Bill O'Donnell]

On Thu, Feb 22, 2024 at 09:22:52AM -0600, Eric Sandeen wrote:
> As filesystems are converted to the new mount API, informational messages,
> errors, and warnings are being routed through infof, errorf, and warnf
> type functions provided by the mount API, which places these messages in
> the log buffer associated with the filesystem context rather than
> in the kernel log / dmesg.
> 
> However, userspace is not yet extracting these messages, so they are
> essentially getting lost. mount(8) still refers the user to dmesg(1)
> on failure.
> 
> At least for now, modify logfc() to always log these messages to dmesg
> as well as to the fileystem context. This way we can continue converting
> filesystems to the new mount API interfaces without worrying about losing
> this information until userspace can retrieve it.
> 
> Signed-off-by: Eric Sandeen <sandeen@redhat.com>

Reviewed-by: Bill O'Donnell <bodonnel@redhat.com>

> ---
> 
> A few considerations/concerns:
> 
> * viro suggested that maybe this should be conditional - possibly config
> 
> * systemd is currently probing with a dummy mount option which will
>   generate noise, see
>   https://github.com/systemd/systemd/blob/main/src/basic/mountpoint-util.c#L759
>   i.e. - 
>   [   10.689256] proc: Unknown parameter 'adefinitelynotexistingmountoption'
>   [   10.801045] tmpfs: Unknown parameter 'adefinitelynotexistingmountoption'
>   [   11.119431] proc: Unknown parameter 'adefinitelynotexistingmountoption'
>   [   11.692032] proc: Unknown parameter 'adefinitelynotexistingmountoption'
> 
> * will this generate other dmesg noise in general if the mount api messages
>   are more noisy in general? (spot-checking old conversions, I don't think so.)
> 
>  fs/fs_context.c | 38 ++++++++++++++++++++------------------
>  1 file changed, 20 insertions(+), 18 deletions(-)
> 
> diff --git a/fs/fs_context.c b/fs/fs_context.c
> index 98589aae5208..3c78b99d5cae 100644
> --- a/fs/fs_context.c
> +++ b/fs/fs_context.c
> @@ -427,8 +427,8 @@ struct fs_context *vfs_dup_fs_context(struct fs_context *src_fc)
>  EXPORT_SYMBOL(vfs_dup_fs_context);
>  
>  /**
> - * logfc - Log a message to a filesystem context
> - * @log: The filesystem context to log to, or NULL to use printk.
> + * logfc - Log a message to dmesg and optionally a filesystem context
> + * @log: The filesystem context to log to, or NULL to use printk alone
>   * @prefix: A string to prefix the output with, or NULL.
>   * @level: 'w' for a warning, 'e' for an error.  Anything else is a notice.
>   * @fmt: The format of the buffer.
> @@ -439,22 +439,24 @@ void logfc(struct fc_log *log, const char *prefix, char level, const char *fmt,
>  	struct va_format vaf = {.fmt = fmt, .va = &va};
>  
>  	va_start(va, fmt);
> -	if (!log) {
> -		switch (level) {
> -		case 'w':
> -			printk(KERN_WARNING "%s%s%pV\n", prefix ? prefix : "",
> -						prefix ? ": " : "", &vaf);
> -			break;
> -		case 'e':
> -			printk(KERN_ERR "%s%s%pV\n", prefix ? prefix : "",
> -						prefix ? ": " : "", &vaf);
> -			break;
> -		default:
> -			printk(KERN_NOTICE "%s%s%pV\n", prefix ? prefix : "",
> -						prefix ? ": " : "", &vaf);
> -			break;
> -		}
> -	} else {
> +	switch (level) {
> +	case 'w':
> +		printk(KERN_WARNING "%s%s%pV\n", prefix ? prefix : "",
> +					prefix ? ": " : "", &vaf);
> +		break;
> +	case 'e':
> +		printk(KERN_ERR "%s%s%pV\n", prefix ? prefix : "",
> +					prefix ? ": " : "", &vaf);
> +		break;
> +	default:
> +		printk(KERN_NOTICE "%s%s%pV\n", prefix ? prefix : "",
> +					prefix ? ": " : "", &vaf);
> +		break;
> +	}
> +	va_end(va);
> +
> +	va_start(va, fmt);
> +	if (log) {
>  		unsigned int logsize = ARRAY_SIZE(log->buffer);
>  		u8 index;
>  		char *q = kasprintf(GFP_KERNEL, "%c %s%s%pV\n", level,
> -- 
> 2.43.0
> 

Re: [PATCH RFC] vfs: always log mount API fs context messages to dmesg

[Darrick J. Wong]

On Thu, Feb 22, 2024 at 09:58:24AM -0600, Bill O'Donnell wrote:
> On Thu, Feb 22, 2024 at 09:22:52AM -0600, Eric Sandeen wrote:
> > As filesystems are converted to the new mount API, informational messages,
> > errors, and warnings are being routed through infof, errorf, and warnf
> > type functions provided by the mount API, which places these messages in
> > the log buffer associated with the filesystem context rather than
> > in the kernel log / dmesg.
> > 
> > However, userspace is not yet extracting these messages, so they are
> > essentially getting lost. mount(8) still refers the user to dmesg(1)
> > on failure.

Eric pointed me at a sample program (over irc) that revealed that one
can read() the fd returned by fsopen() to obtain these messages.  I had
no idea that was possible... because there are no manpages for these
system calls!

Can we /please/ document and write (more) fstests for these things?
[that was mostly aimed at dhowells]

--D

> > At least for now, modify logfc() to always log these messages to dmesg
> > as well as to the fileystem context. This way we can continue converting
> > filesystems to the new mount API interfaces without worrying about losing
> > this information until userspace can retrieve it.
> > 
> > Signed-off-by: Eric Sandeen <sandeen@redhat.com>
> 
> Reviewed-by: Bill O'Donnell <bodonnel@redhat.com>
> 
> > ---
> > 
> > A few considerations/concerns:
> > 
> > * viro suggested that maybe this should be conditional - possibly config
> > 
> > * systemd is currently probing with a dummy mount option which will
> >   generate noise, see
> >   https://github.com/systemd/systemd/blob/main/src/basic/mountpoint-util.c#L759
> >   i.e. - 
> >   [   10.689256] proc: Unknown parameter 'adefinitelynotexistingmountoption'
> >   [   10.801045] tmpfs: Unknown parameter 'adefinitelynotexistingmountoption'
> >   [   11.119431] proc: Unknown parameter 'adefinitelynotexistingmountoption'
> >   [   11.692032] proc: Unknown parameter 'adefinitelynotexistingmountoption'
> > 
> > * will this generate other dmesg noise in general if the mount api messages
> >   are more noisy in general? (spot-checking old conversions, I don't think so.)
> > 
> >  fs/fs_context.c | 38 ++++++++++++++++++++------------------
> >  1 file changed, 20 insertions(+), 18 deletions(-)
> > 
> > diff --git a/fs/fs_context.c b/fs/fs_context.c
> > index 98589aae5208..3c78b99d5cae 100644
> > --- a/fs/fs_context.c
> > +++ b/fs/fs_context.c
> > @@ -427,8 +427,8 @@ struct fs_context *vfs_dup_fs_context(struct fs_context *src_fc)
> >  EXPORT_SYMBOL(vfs_dup_fs_context);
> >  
> >  /**
> > - * logfc - Log a message to a filesystem context
> > - * @log: The filesystem context to log to, or NULL to use printk.
> > + * logfc - Log a message to dmesg and optionally a filesystem context
> > + * @log: The filesystem context to log to, or NULL to use printk alone
> >   * @prefix: A string to prefix the output with, or NULL.
> >   * @level: 'w' for a warning, 'e' for an error.  Anything else is a notice.
> >   * @fmt: The format of the buffer.
> > @@ -439,22 +439,24 @@ void logfc(struct fc_log *log, const char *prefix, char level, const char *fmt,
> >  	struct va_format vaf = {.fmt = fmt, .va = &va};
> >  
> >  	va_start(va, fmt);
> > -	if (!log) {
> > -		switch (level) {
> > -		case 'w':
> > -			printk(KERN_WARNING "%s%s%pV\n", prefix ? prefix : "",
> > -						prefix ? ": " : "", &vaf);
> > -			break;
> > -		case 'e':
> > -			printk(KERN_ERR "%s%s%pV\n", prefix ? prefix : "",
> > -						prefix ? ": " : "", &vaf);
> > -			break;
> > -		default:
> > -			printk(KERN_NOTICE "%s%s%pV\n", prefix ? prefix : "",
> > -						prefix ? ": " : "", &vaf);
> > -			break;
> > -		}
> > -	} else {
> > +	switch (level) {
> > +	case 'w':
> > +		printk(KERN_WARNING "%s%s%pV\n", prefix ? prefix : "",
> > +					prefix ? ": " : "", &vaf);
> > +		break;
> > +	case 'e':
> > +		printk(KERN_ERR "%s%s%pV\n", prefix ? prefix : "",
> > +					prefix ? ": " : "", &vaf);
> > +		break;
> > +	default:
> > +		printk(KERN_NOTICE "%s%s%pV\n", prefix ? prefix : "",
> > +					prefix ? ": " : "", &vaf);
> > +		break;
> > +	}
> > +	va_end(va);
> > +
> > +	va_start(va, fmt);
> > +	if (log) {
> >  		unsigned int logsize = ARRAY_SIZE(log->buffer);
> >  		u8 index;
> >  		char *q = kasprintf(GFP_KERNEL, "%c %s%s%pV\n", level,
> > -- 
> > 2.43.0
> > 
> 
> 

Re: [PATCH RFC] vfs: always log mount API fs context messages to dmesg

[Christian Brauner]

> Can we /please/ document and write (more) fstests for these things?

So fstests I've written quite extensively for at least mount_setattr(2)
and they're part of fstests/src/vfs/ and some other tests for other new
api calls.

A long time ago I got tired of writing groff (or whatever it's called),
and it's tedious semantics and the involved upstreaming process. So a
while ago I just started converting my manpages into markdown and
started updating them and if people were interested in upstreaming this
as groff then they're welcome. So:

https://github.com/brauner/man-pages-md

This also includes David's manpages which I had for a while locally but
didn't convert. So I did that now.

Re: [PATCH RFC] vfs: always log mount API fs context messages to dmesg

[Darrick J. Wong]

On Fri, Feb 23, 2024 at 04:56:34PM +0100, Christian Brauner wrote:
> > Can we /please/ document and write (more) fstests for these things?
> 
> So fstests I've written quite extensively for at least mount_setattr(2)
> and they're part of fstests/src/vfs/ and some other tests for other new
> api calls.
> 
> A long time ago I got tired of writing groff (or whatever it's called),
> and it's tedious semantics and the involved upstreaming process. So a
> while ago I just started converting my manpages into markdown and
> started updating them and if people were interested in upstreaming this
> as groff then they're welcome. So:
> 
> https://github.com/brauner/man-pages-md
> 
> This also includes David's manpages which I had for a while locally but
> didn't convert. So I did that now.

Egad that's so much less fugly.  Do you think we can convince Alejandro
to take some of that without so much demands of splitting things and
whatnot?

(Thanks for keeping those from bitrotting btw)

--D

Re: [PATCH RFC] vfs: always log mount API fs context messages to dmesg

[Christian Brauner]

On Fri, Feb 23, 2024 at 05:58:45PM -0800, Darrick J. Wong wrote:
> On Fri, Feb 23, 2024 at 04:56:34PM +0100, Christian Brauner wrote:
> > > Can we /please/ document and write (more) fstests for these things?
> > 
> > So fstests I've written quite extensively for at least mount_setattr(2)
> > and they're part of fstests/src/vfs/ and some other tests for other new
> > api calls.
> > 
> > A long time ago I got tired of writing groff (or whatever it's called),
> > and it's tedious semantics and the involved upstreaming process. So a
> > while ago I just started converting my manpages into markdown and
> > started updating them and if people were interested in upstreaming this
> > as groff then they're welcome. So:
> > 
> > https://github.com/brauner/man-pages-md
> > 
> > This also includes David's manpages which I had for a while locally but
> > didn't convert. So I did that now.
> 
> Egad that's so much less fugly.  Do you think we can convince Alejandro
> to take some of that without so much demands of splitting things and
> whatnot?

Maybe. I'll make a note to return to this at some point. Hm, I need to
update move_mount() again. I just realized.

Re: [PATCH RFC] vfs: always log mount API fs context messages to dmesg

[Christian Brauner]

On Thu, Feb 22, 2024 at 09:22:52AM -0600, Eric Sandeen wrote:
> As filesystems are converted to the new mount API, informational messages,
> errors, and warnings are being routed through infof, errorf, and warnf
> type functions provided by the mount API, which places these messages in
> the log buffer associated with the filesystem context rather than
> in the kernel log / dmesg.
> 
> However, userspace is not yet extracting these messages, so they are
> essentially getting lost. mount(8) still refers the user to dmesg(1)
> on failure.

I mean sure we can do this. But we should try without a Kconfig option
for this.

But mount(8) and util-linux have been switched to the new mount api in
v2.39 and libmount already has the code to read and print the error
messages:

https://github.com/util-linux/util-linux/blob/7ca98ca6aab919f271a15e40276cbb411e62f0e4/libmount/src/hook_mount.c#L68

but it's hidden behind DEBUG. So to me it seems much easier to just make
util-linux and log those extra messages than start putting them into
dmesg. Can't we try that first?

Re: [PATCH RFC] vfs: always log mount API fs context messages to dmesg

[Eric Sandeen]

On 2/23/24 9:06 AM, Christian Brauner wrote:
> On Thu, Feb 22, 2024 at 09:22:52AM -0600, Eric Sandeen wrote:
>> As filesystems are converted to the new mount API, informational messages,
>> errors, and warnings are being routed through infof, errorf, and warnf
>> type functions provided by the mount API, which places these messages in
>> the log buffer associated with the filesystem context rather than
>> in the kernel log / dmesg.
>>
>> However, userspace is not yet extracting these messages, so they are
>> essentially getting lost. mount(8) still refers the user to dmesg(1)
>> on failure.
> 
> I mean sure we can do this. But we should try without a Kconfig option
> for this.
> 
> But mount(8) and util-linux have been switched to the new mount api in
> v2.39 and libmount already has the code to read and print the error
> messages:
> 
> https://github.com/util-linux/util-linux/blob/7ca98ca6aab919f271a15e40276cbb411e62f0e4/libmount/src/hook_mount.c#L68

*nod*

> but it's hidden behind DEBUG.

Yup.

> So to me it seems much easier to just make
> util-linux and log those extra messages than start putting them into
> dmesg. Can't we try that first?

Sounds fine. Since we're trying to get a few more filesystems
converted (hopefully all!) I just wanted to be sure that doing so
doesn't end up losing useful information for the user.

I guess we could do conversions in 2 passes, and wait to switch to
warnf() and friends until util-linux makes use of it, but I'd hoped to
not have to touch everything twice, hence thinking about logging to
dmesg in the short term.

But there are downsides and complexities to that as well. I'm not
wedded to it, hence the RFC. :)

Let's see what kzak thinks? We could also just delay any conversions
that would need to pipe information through warnf().

Thanks,
-Eric

Re: [PATCH RFC] vfs: always log mount API fs context messages to dmesg

[Christian Brauner]

On Fri, Feb 23, 2024 at 10:27:54AM -0600, Eric Sandeen wrote:
> On 2/23/24 9:06 AM, Christian Brauner wrote:
> > On Thu, Feb 22, 2024 at 09:22:52AM -0600, Eric Sandeen wrote:
> >> As filesystems are converted to the new mount API, informational messages,
> >> errors, and warnings are being routed through infof, errorf, and warnf
> >> type functions provided by the mount API, which places these messages in
> >> the log buffer associated with the filesystem context rather than
> >> in the kernel log / dmesg.
> >>
> >> However, userspace is not yet extracting these messages, so they are
> >> essentially getting lost. mount(8) still refers the user to dmesg(1)
> >> on failure.
> > 
> > I mean sure we can do this. But we should try without a Kconfig option
> > for this.
> > 
> > But mount(8) and util-linux have been switched to the new mount api in
> > v2.39 and libmount already has the code to read and print the error
> > messages:
> > 
> > https://github.com/util-linux/util-linux/blob/7ca98ca6aab919f271a15e40276cbb411e62f0e4/libmount/src/hook_mount.c#L68
> 
> *nod*
> 
> > but it's hidden behind DEBUG.
> 
> Yup.
> 
> > So to me it seems much easier to just make
> > util-linux and log those extra messages than start putting them into
> > dmesg. Can't we try that first?
> 
> Sounds fine. Since we're trying to get a few more filesystems
> converted (hopefully all!) I just wanted to be sure that doing so
> doesn't end up losing useful information for the user.

I see.

Re: [PATCH RFC] vfs: always log mount API fs context messages to dmesg

[Karel Zak]

On Fri, Feb 23, 2024 at 04:06:29PM +0100, Christian Brauner wrote:
> On Thu, Feb 22, 2024 at 09:22:52AM -0600, Eric Sandeen wrote:
> > As filesystems are converted to the new mount API, informational messages,
> > errors, and warnings are being routed through infof, errorf, and warnf
> > type functions provided by the mount API, which places these messages in
> > the log buffer associated with the filesystem context rather than
> > in the kernel log / dmesg.
> > 
> > However, userspace is not yet extracting these messages, so they are
> > essentially getting lost. mount(8) still refers the user to dmesg(1)
> > on failure.
> 
> I mean sure we can do this. But we should try without a Kconfig option
> for this.
> 
> But mount(8) and util-linux have been switched to the new mount api in
> v2.39 and libmount already has the code to read and print the error
> messages:
> 
> https://github.com/util-linux/util-linux/blob/7ca98ca6aab919f271a15e40276cbb411e62f0e4/libmount/src/hook_mount.c#L68
> 
> but it's hidden behind DEBUG. So to me it seems much easier to just make
> util-linux and log those extra messages than start putting them into
> dmesg. Can't we try that first?

While it's true that libmount should be more intelligent in this
regard, I still believe that having all the messages accessible via
dmesg(1) is a good idea.

dmesg(1) collects messages from multiple mount calls, making it easy
to access messages generated by mount(8) when invoked from scripts,
systemd, etc. Having a single point to check for errors is convenient.

And dmesg(8) is also the traditional location where users and
documentation expect to find errors.

    Karel

-- 
 Karel Zak  <kzak@redhat.com>
 http://karelzak.blogspot.com

Re: [PATCH RFC] vfs: always log mount API fs context messages to dmesg

[Kent Overstreet]

On Fri, Feb 23, 2024 at 04:06:29PM +0100, Christian Brauner wrote:
> On Thu, Feb 22, 2024 at 09:22:52AM -0600, Eric Sandeen wrote:
> > As filesystems are converted to the new mount API, informational messages,
> > errors, and warnings are being routed through infof, errorf, and warnf
> > type functions provided by the mount API, which places these messages in
> > the log buffer associated with the filesystem context rather than
> > in the kernel log / dmesg.
> > 
> > However, userspace is not yet extracting these messages, so they are
> > essentially getting lost. mount(8) still refers the user to dmesg(1)
> > on failure.
> 
> I mean sure we can do this. But we should try without a Kconfig option
> for this.
> 
> But mount(8) and util-linux have been switched to the new mount api in
> v2.39 and libmount already has the code to read and print the error
> messages:

Why was there not an API flag to indicate when userspace is listening
for these?

Re: [PATCH RFC] vfs: always log mount API fs context messages to dmesg

[Christian Brauner]

> * systemd is currently probing with a dummy mount option which will
>   generate noise, see
>   https://github.com/systemd/systemd/blob/main/src/basic/mountpoint-util.c#L759
>   i.e. - 
>   [   10.689256] proc: Unknown parameter 'adefinitelynotexistingmountoption'
>   [   10.801045] tmpfs: Unknown parameter 'adefinitelynotexistingmountoption'
>   [   11.119431] proc: Unknown parameter 'adefinitelynotexistingmountoption'
>   [   11.692032] proc: Unknown parameter 'adefinitelynotexistingmountoption'

Yeah, I remember that they want to know whether a given mount option is
supported or not. That would potentially cause some people to pipe up
complaining about dmesg getting spammed with this if we enable it.

Ok, so right now invalfc() is logged in the fs_context but it isn't
logged in dmesg, right? Would it make sense to massage invalfc() so that
it logs with error into the fs_context but with info into dmesg? This
would avoid spamming dmesg and then we could risk turning this on to see
whether this causes complaints.

You know you could probably test your patch with xfstests to see if this
causes any new test failures because dmesg contains new output. This
doesn't disqualify the patch ofc it might just useful to get an idea how
much noiser we are by doing this.

Re: [PATCH RFC] vfs: always log mount API fs context messages to dmesg

[Eric Sandeen]

On 2/26/24 5:27 AM, Christian Brauner wrote:
>> * systemd is currently probing with a dummy mount option which will
>>   generate noise, see
>>   https://github.com/systemd/systemd/blob/main/src/basic/mountpoint-util.c#L759
>>   i.e. - 
>>   [   10.689256] proc: Unknown parameter 'adefinitelynotexistingmountoption'
>>   [   10.801045] tmpfs: Unknown parameter 'adefinitelynotexistingmountoption'
>>   [   11.119431] proc: Unknown parameter 'adefinitelynotexistingmountoption'
>>   [   11.692032] proc: Unknown parameter 'adefinitelynotexistingmountoption'
> 
> Yeah, I remember that they want to know whether a given mount option is
> supported or not. That would potentially cause some people to pipe up
> complaining about dmesg getting spammed with this if we enable it.
> 
> Ok, so right now invalfc() is logged in the fs_context but it isn't
> logged in dmesg, right? Would it make sense to massage invalfc() so that
> it logs with error into the fs_context but with info into dmesg? This
> would avoid spamming dmesg and then we could risk turning this on to see
> whether this causes complaints.

Hm, yeah that would make sense I think - less consequential messages go only
to the fc, higher priority messages go to both fc and dmesg. (userspace
could still filter on severity for messages in the fc as desired.)

The interfaces are already a little unclear, ("what is warnf vs. warnfc?")
without reading the code, and this'd be another slightly unexpected wrinkle,
but functionally it makes sense to me. I wonder if a sysctl to set a
severity threshold for dmesg would make any sense, or if that'd be overkill.

> You know you could probably test your patch with xfstests to see if this
> causes any new test failures because dmesg contains new output. This
> doesn't disqualify the patch ofc it might just useful to get an idea how
> much noiser we are by doing this.

Good point. Ok, it sounds like there's some movement towards agreement that
at least some messages should go to dmesg. I'll dig a little deeper and come
up with a more solid & tested proposal.

Thanks,
-Eric

Re: [PATCH RFC] vfs: always log mount API fs context messages to dmesg

[Ian Kent]

On 26/2/24 23:23, Eric Sandeen wrote:
> On 2/26/24 5:27 AM, Christian Brauner wrote:
>>> * systemd is currently probing with a dummy mount option which will
>>>    generate noise, see
>>>    https://github.com/systemd/systemd/blob/main/src/basic/mountpoint-util.c#L759
>>>    i.e. -
>>>    [   10.689256] proc: Unknown parameter 'adefinitelynotexistingmountoption'
>>>    [   10.801045] tmpfs: Unknown parameter 'adefinitelynotexistingmountoption'
>>>    [   11.119431] proc: Unknown parameter 'adefinitelynotexistingmountoption'
>>>    [   11.692032] proc: Unknown parameter 'adefinitelynotexistingmountoption'
>> Yeah, I remember that they want to know whether a given mount option is
>> supported or not. That would potentially cause some people to pipe up
>> complaining about dmesg getting spammed with this if we enable it.
>>
>> Ok, so right now invalfc() is logged in the fs_context but it isn't
>> logged in dmesg, right? Would it make sense to massage invalfc() so that
>> it logs with error into the fs_context but with info into dmesg? This
>> would avoid spamming dmesg and then we could risk turning this on to see
>> whether this causes complaints.
> Hm, yeah that would make sense I think - less consequential messages go only
> to the fc, higher priority messages go to both fc and dmesg. (userspace
> could still filter on severity for messages in the fc as desired.)
>
> The interfaces are already a little unclear, ("what is warnf vs. warnfc?")
> without reading the code, and this'd be another slightly unexpected wrinkle,
> but functionally it makes sense to me. I wonder if a sysctl to set a
> severity threshold for dmesg would make any sense, or if that'd be overkill.

A case that I encountered quite a while ago was where (IIRC) a kernel NFS

bug was logged because of the appearance of a new message in the kernel log.


I investigated and explained that what the message said had already been

happening but was not previously logged and the reason the message was now

appearing was due to code changes (the mount api).


At this point it becomes annoying, when the user isn't happy with the

explanation and doesn't quite say so but continues to complain. Admittedly

I didn't say I wasn't going to change it but then I didn't implement the

change and I'm not an NFS maintainer so maybe I should have ignored the

bug ...


It was then I thought the mount api logging needed so more thought and

here we are.


Perhaps, if we had some way to change the log level of messages via

configuration, sysfs perhaps, so that what gets logged to the kernel

log can be better controlled. An additional (or perhaps different scale)

log level that can allow finer grained control of what gets logged might

be sufficient.


TBH I'm not really sure the best way to improve the situation, all I know

is we do need continue to log messages to the kernel log, where appropriate

and we do need a way to ensure all messages are available in the context.


Ian

>> You know you could probably test your patch with xfstests to see if this
>> causes any new test failures because dmesg contains new output. This
>> doesn't disqualify the patch ofc it might just useful to get an idea how
>> much noiser we are by doing this.
> Good point. Ok, it sounds like there's some movement towards agreement that
> at least some messages should go to dmesg. I'll dig a little deeper and come
> up with a more solid & tested proposal.
>
> Thanks,
> -Eric
>
>