diff mbox series

[3/3] xfs: shorten the shutdown messages to a single line

Message ID 162404245053.2377241.2678360661858649500.stgit@locust (mailing list archive)
State Accepted
Headers show
Series xfs: various small fixes and cleanups | expand

Commit Message

Darrick J. Wong June 18, 2021, 6:54 p.m. UTC
From: Darrick J. Wong <djwong@kernel.org>

Consolidate the shutdown messages to a single line containing the
reason, the passed-in flags, the source of the shutdown, and the end
result.  This means we now only have one line to look for when
debugging, which is useful when the fs goes down while something else is
flooding dmesg.

Signed-off-by: Darrick J. Wong <djwong@kernel.org>
---
 fs/xfs/xfs_fsops.c |   16 ++++++++--------
 1 file changed, 8 insertions(+), 8 deletions(-)

Comments

Dave Chinner June 20, 2021, 10:29 p.m. UTC | #1
On Fri, Jun 18, 2021 at 11:54:10AM -0700, Darrick J. Wong wrote:
> From: Darrick J. Wong <djwong@kernel.org>
> 
> Consolidate the shutdown messages to a single line containing the
> reason, the passed-in flags, the source of the shutdown, and the end
> result.  This means we now only have one line to look for when
> debugging, which is useful when the fs goes down while something else is
> flooding dmesg.
> 
> Signed-off-by: Darrick J. Wong <djwong@kernel.org>

Seems reasonable. There's enough commonality for log scrapers to
easily be able to grab either old or new messages.

Reviewed-by: Dave Chinner <dchinner@redhat.com>
Chandan Babu R June 21, 2021, 4:41 a.m. UTC | #2
On 19 Jun 2021 at 00:24, Darrick J. Wong wrote:
> From: Darrick J. Wong <djwong@kernel.org>
>
> Consolidate the shutdown messages to a single line containing the
> reason, the passed-in flags, the source of the shutdown, and the end
> result.  This means we now only have one line to look for when
> debugging, which is useful when the fs goes down while something else is
> flooding dmesg.
>

Looks good.

Reviewed-by: Chandan Babu R <chandanrlinux@gmail.com>

> Signed-off-by: Darrick J. Wong <djwong@kernel.org>
> ---
>  fs/xfs/xfs_fsops.c |   16 ++++++++--------
>  1 file changed, 8 insertions(+), 8 deletions(-)
>
>
> diff --git a/fs/xfs/xfs_fsops.c b/fs/xfs/xfs_fsops.c
> index b7f979eca1e2..6ed29b158312 100644
> --- a/fs/xfs/xfs_fsops.c
> +++ b/fs/xfs/xfs_fsops.c
> @@ -538,25 +538,25 @@ xfs_do_force_shutdown(
>  
>  	if (flags & SHUTDOWN_FORCE_UMOUNT) {
>  		xfs_alert(mp,
> -"User initiated shutdown received. Shutting down filesystem");
> +"User initiated shutdown (0x%x) received. Shutting down filesystem",
> +				flags);
>  		return;
>  	}
>  
> -	xfs_notice(mp,
> -"%s(0x%x) called from line %d of file %s. Return address = %pS",
> -		__func__, flags, lnnum, fname, __return_address);
> -
>  	if (flags & SHUTDOWN_CORRUPT_INCORE) {
>  		xfs_alert_tag(mp, XFS_PTAG_SHUTDOWN_CORRUPT,
> -"Corruption of in-memory data detected.  Shutting down filesystem");
> +"Corruption of in-memory data (0x%x) detected at %pS (%s:%d).  Shutting down filesystem",
> +				flags, __return_address, fname, lnnum);
>  		if (XFS_ERRLEVEL_HIGH <= xfs_error_level)
>  			xfs_stack_trace();
>  	} else if (logerror) {
>  		xfs_alert_tag(mp, XFS_PTAG_SHUTDOWN_LOGERROR,
> -			"Log I/O Error Detected. Shutting down filesystem");
> +"Log I/O error (0x%x) detected at %pS (%s:%d). Shutting down filesystem",
> +				flags, __return_address, fname, lnnum);
>  	} else {
>  		xfs_alert_tag(mp, XFS_PTAG_SHUTDOWN_IOERROR,
> -			"I/O Error Detected. Shutting down filesystem");
> +"I/O error (0x%x) detected at %pS (%s:%d). Shutting down filesystem",
> +				flags, __return_address, fname, lnnum);
>  	}
>  
>  	xfs_alert(mp,
Christoph Hellwig June 21, 2021, 5:30 a.m. UTC | #3
On Fri, Jun 18, 2021 at 11:54:10AM -0700, Darrick J. Wong wrote:
> From: Darrick J. Wong <djwong@kernel.org>
> 
> Consolidate the shutdown messages to a single line containing the
> reason, the passed-in flags, the source of the shutdown, and the end
> result.  This means we now only have one line to look for when
> debugging, which is useful when the fs goes down while something else is
> flooding dmesg.
> 
> Signed-off-by: Darrick J. Wong <djwong@kernel.org>
> ---
>  fs/xfs/xfs_fsops.c |   16 ++++++++--------
>  1 file changed, 8 insertions(+), 8 deletions(-)
> 
> 
> diff --git a/fs/xfs/xfs_fsops.c b/fs/xfs/xfs_fsops.c
> index b7f979eca1e2..6ed29b158312 100644
> --- a/fs/xfs/xfs_fsops.c
> +++ b/fs/xfs/xfs_fsops.c
> @@ -538,25 +538,25 @@ xfs_do_force_shutdown(
>  
>  	if (flags & SHUTDOWN_FORCE_UMOUNT) {
>  		xfs_alert(mp,
> -"User initiated shutdown received. Shutting down filesystem");
> +"User initiated shutdown (0x%x) received. Shutting down filesystem",
> +				flags);
>  		return;
>  	}

So SHUTDOWN_FORCE_UMOUNT can actually be used together with
SHUTDOWN_LOG_IO_ERROR so printing something more specific could be
useful, although I'd prefer text over the hex flags.

>  	if (flags & SHUTDOWN_CORRUPT_INCORE) {
>  		xfs_alert_tag(mp, XFS_PTAG_SHUTDOWN_CORRUPT,
> -"Corruption of in-memory data detected.  Shutting down filesystem");
> +"Corruption of in-memory data (0x%x) detected at %pS (%s:%d).  Shutting down filesystem",
> +				flags, __return_address, fname, lnnum);
>  		if (XFS_ERRLEVEL_HIGH <= xfs_error_level)
>  			xfs_stack_trace();
>  	} else if (logerror) {
>  		xfs_alert_tag(mp, XFS_PTAG_SHUTDOWN_LOGERROR,
> -			"Log I/O Error Detected. Shutting down filesystem");
> +"Log I/O error (0x%x) detected at %pS (%s:%d). Shutting down filesystem",
> +				flags, __return_address, fname, lnnum);
>  	} else {
>  		xfs_alert_tag(mp, XFS_PTAG_SHUTDOWN_IOERROR,
> -			"I/O Error Detected. Shutting down filesystem");
> +"I/O error (0x%x) detected at %pS (%s:%d). Shutting down filesystem",
> +				flags, __return_address, fname, lnnum);
>  	}

However once we get here, flags can have exactly one specific value,
so printing it (especially as unreadable hex value) is completely
pointless.
Dave Chinner June 21, 2021, 6:02 a.m. UTC | #4
On Mon, Jun 21, 2021 at 06:30:27AM +0100, Christoph Hellwig wrote:
> On Fri, Jun 18, 2021 at 11:54:10AM -0700, Darrick J. Wong wrote:
> > From: Darrick J. Wong <djwong@kernel.org>
> > 
> > Consolidate the shutdown messages to a single line containing the
> > reason, the passed-in flags, the source of the shutdown, and the end
> > result.  This means we now only have one line to look for when
> > debugging, which is useful when the fs goes down while something else is
> > flooding dmesg.
> > 
> > Signed-off-by: Darrick J. Wong <djwong@kernel.org>
> > ---
> >  fs/xfs/xfs_fsops.c |   16 ++++++++--------
> >  1 file changed, 8 insertions(+), 8 deletions(-)
> > 
> > 
> > diff --git a/fs/xfs/xfs_fsops.c b/fs/xfs/xfs_fsops.c
> > index b7f979eca1e2..6ed29b158312 100644
> > --- a/fs/xfs/xfs_fsops.c
> > +++ b/fs/xfs/xfs_fsops.c
> > @@ -538,25 +538,25 @@ xfs_do_force_shutdown(
> >  
> >  	if (flags & SHUTDOWN_FORCE_UMOUNT) {
> >  		xfs_alert(mp,
> > -"User initiated shutdown received. Shutting down filesystem");
> > +"User initiated shutdown (0x%x) received. Shutting down filesystem",
> > +				flags);
> >  		return;
> >  	}
> 
> So SHUTDOWN_FORCE_UMOUNT can actually be used together with
> SHUTDOWN_LOG_IO_ERROR so printing something more specific could be
> useful, although I'd prefer text over the hex flags.

I'm in the process of reworking the shutdown code because shutdown
is so, so very broken. Can we just fix the message and stop moving
the goal posts on me while I try to fix bugs?

Cheers,

Dave.
Christoph Hellwig June 21, 2021, 6:06 a.m. UTC | #5
On Mon, Jun 21, 2021 at 04:02:22PM +1000, Dave Chinner wrote:
> > >  	if (flags & SHUTDOWN_FORCE_UMOUNT) {
> > >  		xfs_alert(mp,
> > > -"User initiated shutdown received. Shutting down filesystem");
> > > +"User initiated shutdown (0x%x) received. Shutting down filesystem",
> > > +				flags);
> > >  		return;
> > >  	}
> > 
> > So SHUTDOWN_FORCE_UMOUNT can actually be used together with
> > SHUTDOWN_LOG_IO_ERROR so printing something more specific could be
> > useful, although I'd prefer text over the hex flags.
> 
> I'm in the process of reworking the shutdown code because shutdown
> is so, so very broken. Can we just fix the message and stop moving
> the goal posts on me while I try to fix bugs?

I suggest just not adding these not very useful flags.  That is not
moving the goal post.  And I'm growing really tried of this pointlessly
aggressive attitude.
Dave Chinner June 21, 2021, 6:29 a.m. UTC | #6
On Mon, Jun 21, 2021 at 07:06:40AM +0100, Christoph Hellwig wrote:
> On Mon, Jun 21, 2021 at 04:02:22PM +1000, Dave Chinner wrote:
> > > >  	if (flags & SHUTDOWN_FORCE_UMOUNT) {
> > > >  		xfs_alert(mp,
> > > > -"User initiated shutdown received. Shutting down filesystem");
> > > > +"User initiated shutdown (0x%x) received. Shutting down filesystem",
> > > > +				flags);
> > > >  		return;
> > > >  	}
> > > 
> > > So SHUTDOWN_FORCE_UMOUNT can actually be used together with
> > > SHUTDOWN_LOG_IO_ERROR so printing something more specific could be
> > > useful, although I'd prefer text over the hex flags.
> > 
> > I'm in the process of reworking the shutdown code because shutdown
> > is so, so very broken. Can we just fix the message and stop moving
> > the goal posts on me while I try to fix bugs?
> 
> I suggest just not adding these not very useful flags.  That is not
> moving the goal post.  And I'm growing really tried of this pointlessly
> aggressive attitude.

Aggressive? Not at all. I'm being realistic.

We've still got bugs in the for-next tree that need to be fixed and
this code is part of the problem. It's already -rc7 and we need to
focus on understanding the bugs in for-next well enough to either
fix them or revert them.

Cosmetic concerns about the code are extremely low priority right
now, so can you please just have a little patience here and wait for
me to deal with the bugs rather than bikeshedding log messages that
might not even exist in a couple of days time?

-Dave.
Darrick J. Wong June 21, 2021, 4:56 p.m. UTC | #7
On Mon, Jun 21, 2021 at 04:29:29PM +1000, Dave Chinner wrote:
> On Mon, Jun 21, 2021 at 07:06:40AM +0100, Christoph Hellwig wrote:
> > On Mon, Jun 21, 2021 at 04:02:22PM +1000, Dave Chinner wrote:
> > > > >  	if (flags & SHUTDOWN_FORCE_UMOUNT) {
> > > > >  		xfs_alert(mp,
> > > > > -"User initiated shutdown received. Shutting down filesystem");
> > > > > +"User initiated shutdown (0x%x) received. Shutting down filesystem",
> > > > > +				flags);
> > > > >  		return;
> > > > >  	}
> > > > 
> > > > So SHUTDOWN_FORCE_UMOUNT can actually be used together with
> > > > SHUTDOWN_LOG_IO_ERROR so printing something more specific could be
> > > > useful, although I'd prefer text over the hex flags.
> > > 
> > > I'm in the process of reworking the shutdown code because shutdown
> > > is so, so very broken. Can we just fix the message and stop moving
> > > the goal posts on me while I try to fix bugs?
> > 
> > I suggest just not adding these not very useful flags.  That is not
> > moving the goal post.  And I'm growing really tried of this pointlessly
> > aggressive attitude.
> 
> Aggressive? Not at all. I'm being realistic.
> 
> We've still got bugs in the for-next tree that need to be fixed and
> this code is part of the problem. It's already -rc7 and we need to
> focus on understanding the bugs in for-next well enough to either
> fix them or revert them.
> 
> Cosmetic concerns about the code are extremely low priority right
> now, so can you please just have a little patience here and wait for
> me to deal with the bugs rather than bikeshedding log messages that
> might not even exist in a couple of days time?

FWIW I /did/ notice that the flags usage could be turned into an enum
and intentionally left that cleanup (and the "int logerror" sprinkled
everywhere) for 5.15.  Maybe Dave will beat me to it, who knows.

--D

> 
> -Dave.
> -- 
> Dave Chinner
> david@fromorbit.com
diff mbox series

Patch

diff --git a/fs/xfs/xfs_fsops.c b/fs/xfs/xfs_fsops.c
index b7f979eca1e2..6ed29b158312 100644
--- a/fs/xfs/xfs_fsops.c
+++ b/fs/xfs/xfs_fsops.c
@@ -538,25 +538,25 @@  xfs_do_force_shutdown(
 
 	if (flags & SHUTDOWN_FORCE_UMOUNT) {
 		xfs_alert(mp,
-"User initiated shutdown received. Shutting down filesystem");
+"User initiated shutdown (0x%x) received. Shutting down filesystem",
+				flags);
 		return;
 	}
 
-	xfs_notice(mp,
-"%s(0x%x) called from line %d of file %s. Return address = %pS",
-		__func__, flags, lnnum, fname, __return_address);
-
 	if (flags & SHUTDOWN_CORRUPT_INCORE) {
 		xfs_alert_tag(mp, XFS_PTAG_SHUTDOWN_CORRUPT,
-"Corruption of in-memory data detected.  Shutting down filesystem");
+"Corruption of in-memory data (0x%x) detected at %pS (%s:%d).  Shutting down filesystem",
+				flags, __return_address, fname, lnnum);
 		if (XFS_ERRLEVEL_HIGH <= xfs_error_level)
 			xfs_stack_trace();
 	} else if (logerror) {
 		xfs_alert_tag(mp, XFS_PTAG_SHUTDOWN_LOGERROR,
-			"Log I/O Error Detected. Shutting down filesystem");
+"Log I/O error (0x%x) detected at %pS (%s:%d). Shutting down filesystem",
+				flags, __return_address, fname, lnnum);
 	} else {
 		xfs_alert_tag(mp, XFS_PTAG_SHUTDOWN_IOERROR,
-			"I/O Error Detected. Shutting down filesystem");
+"I/O error (0x%x) detected at %pS (%s:%d). Shutting down filesystem",
+				flags, __return_address, fname, lnnum);
 	}
 
 	xfs_alert(mp,