Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) client-ip=2620:137:e000::1:20;
Date:   Thu, 22 Jun 2023 17:56:17 -0700
From:   Eric Biggers <ebiggers@kernel.org>
To:     Dave Chinner <david@fromorbit.com>
Cc:     syzbot <syzbot+9d0b0d54a8bd799f6ae4@syzkaller.appspotmail.com>,
        dchinner@redhat.com, djwong@kernel.org, hch@lst.de,
        linux-fsdevel@vger.kernel.org, linux-kernel@vger.kernel.org,
        linux-xfs@vger.kernel.org, syzkaller-bugs@googlegroups.com
Subject: Re: [syzbot] [xfs?] WARNING: Reset corrupted AGFL on AG NUM. NUM
 blocks leaked. Please unmount and run xfs_repair.
Message-ID: <20230623005617.GA1949@sol.localdomain>
References: <000000000000ffcb2e05fe9a445c@google.com>
 <ZJKhoxnkNF3VspbP@dread.disaster.area>
 <20230621075421.GA56560@sol.localdomain>
 <ZJQNjFJhLh0C84u/@dread.disaster.area>
MIME-Version: 1.0
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
In-Reply-To: <ZJQNjFJhLh0C84u/@dread.disaster.area>
Precedence: bulk

On Thu, Jun 22, 2023 at 06:59:56PM +1000, Dave Chinner wrote:
> On Wed, Jun 21, 2023 at 12:54:21AM -0700, Eric Biggers wrote:
> > On Wed, Jun 21, 2023 at 05:07:15PM +1000, 'Dave Chinner' via syzkaller-bugs wrote:
> > > On Tue, Jun 20, 2023 at 07:10:19PM -0700, syzbot wrote:
> > > So exactly what is syzbot complaining about here? There's no kernel
> > > issue here at all.
> > > 
> > > Also, I cannot tell syzbot "don't ever report this as a bug again",
> > > so the syzbot developers are going to have to triage and fix this
> > > syzbot problem themselves so it doesn't keep getting reported to
> > > us...
> > 
> > I think the problem here was that XFS logged a message beginning with
> > "WARNING:", followed by a stack trace.  In the log that looks like a warning
> > generated by the WARN_ON() macro, which is meant for reporting recoverable
> > kernel bugs.  It's difficult for any program to understand the log in cases like
> > this.  This is why include/asm-generic/bug.h contains the following comment:
> > 
> >  * Do not include "BUG"/"WARNING" in format strings manually to make these
> >  * conditions distinguishable from kernel issues.
> 
> Nice.
> 
> Syzbot author doesn't like log messages using certain key words
> because it's hard for syzbot to work out what went wrong.
> 
> Gets new rule added to kernel in a comment in some header file that
> almost nobody doing kernel development work ever looks at.
> 
> Nothing was added to the coding style rules or checkpatch so nobody
> is likely to accidentally trip over this new rule that nobody has
> been told about.
> 
> Syzbot maintainer also fails to do an audit of the kernel to remove
> all existing "WARNING" keywords from existing log messages so leaves
> landmines for subsystems to have to handle at some time in the
> future.
> 
> Five years later, syzbot trips over a log message containing WARNING
> in it that was in code introduced before the rule was "introduced".
> Subsystem maintainers are blamed for not know the rule existed.
> 
> Result: *yet again* we are being told that our only option is
> to *change code that is not broken* just to *shut up some fucking
> bot* we have no control over and could happily live without.
> 
> > If you have a constructive suggestion of how all programs that
> > parse the kernel log can identify real warnings reliably without
> > getting confused by cases like this, I'm sure that would be
> > appreciated.  It would need to be documented and then the guidance
> > in bug.h could then be removed.  But until then, the above is the
> > current guidance.
> 
> That is so not the problem here, Eric.
> 

Grepping for "WARNING:" is how other kernel testing systems find WARN_ON's in
the log too.  For example, see _check_dmesg() in common/rc in xfstests.
xfstests fails tests if "WARNING:" is logged.  You might be aware of this, as
you reviewed and applied xfstests commit 47e5d7d2bb17 which added the code.

I understand it's frustrating that Dmitry's attempt to do something about this
problem was incomplete.  I don't think it is helpful to then send a reflexive,
adversarial response that shifts the blame for this longstanding problem with
the kernel logs entirely onto syzbot and even Dmitry personally.  That just
causes confusion about the problem that needs to be solved.

Anyway, either everything that parses the kernel logs needs to be smarter about
identifying real WARN_ON's, or all instances of "WARNING:" need to be eliminated
from the log (with existing code, coding style guidelines, and checkpatch
updated as you mentioned).  I think I'm leaning towards the position that fake
"WARNING:"s should be eliminated.  It does seem like a hack, but it makes the
"obvious" log pattern matching that everyone tends to write work as expected...

If you don't want to help, fine, but at least please try not to be obstructive.

- Eric