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

["Darrick J. Wong" <djwong@kernel.org>]

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
> > 
> 
>