On Tue, Oct 31, 2017 at 02:54:17PM +0800, Eryu Guan wrote:
> On Tue, Oct 31, 2017 at 01:10:41AM +0100, Fengguang Wu wrote:
> > Hi Eryu,
> >
> > On Mon, Oct 30, 2017 at 03:44:29PM +0800, Eryu Guan wrote:
> > > Hi Fengguang,
> > >
> > > On Mon, Oct 30, 2017 at 08:20:21AM +0100, Fengguang Wu wrote:
> > > > CC fsdevel.
> > > >
> > > > On Sun, Oct 29, 2017 at 11:51:55PM +0100, Fengguang Wu wrote:
> > > > > Hi Linus,
> > > > >
> > > > > Up to now we see the below boot error/warnings when testing v4.14-rc6.
> > > > >
> > > > > They hit the RC release mainly due to various imperfections in 0day's
> > > > > auto bisection. So I manually list them here and CC the likely easy to
> > > > > debug ones to the corresponding maintainers in the followup emails.
> > > > >
> > > > > boot_successes: 4700
> > > > > boot_failures: 247
> > > >
> > > > [...]
> > > >
> > > > > WARNING:at_fs/direct-io.c:#dio_complete: 7
> > > > > WARNING:at_fs/iomap.c:#iomap_dio_complete: 3
> > > > > WARNING:at_fs/iomap.c:#iomap_dio_rw: 1
> > > >
> > > > The first warning happens on btrfs and is bisected to this commit.
> > > > The other 2 warnings happen on xfs.
> > >
> > > I noticed that the warnings are triggered by generic/095 and
> > > generic/208, they're known to generate such warnings and I think these
> > > warnings are kind of 'known issue', please see comments above
> > > _filter_aiodio_dmesg() in fstests/common/filter.
> > >
> > > Please make sure your local fstests contains the following 3 commits:
> > >
> > > ca93e26865ab common: move _filter_xfs_dmesg() to common/filter
> > > 5aa662733ab0 common: turn _filter_xfs_dmesg() into _filter_aiodio_dmesg()
> > > 228aee780f13 generic/036,208: whitelist [iomap_]dio_complete() WARNs
> >
> > OK.
> >
> > > we filtered out such warnings in fstests on purpose so the affected
> > > tests won't fail because of such dmesg warnings.
> >
> > We may also teach 0day robot to ignore the warning when running the
> > above 2 fstests.
> >
> > The more generic way of filtering may be to inject a dmesg line like
> >
> > THIS TEST WILL TRIGGER KERNEL WARNING, PLEASE IGNORE.
> >
> > just before the specific tests startup. Then 3rd party dmesg parsing
> > scripts can handle such purpose-made warnings in a uniform way.
>
> fstests doesn't know, prior to the test, if the warnings the test is
> going to trigger are intentional or real bugs, fstests records the dmesg
> log and analyzes the log after test and reports PASS if all the warnings
> are intentional (based on the whitelist filter).
>
> But I think it's possible to insert such a message to dmesg *after* test
> if fstests finds that all the warnings are intentional. Does that work
> for 0day robot?
>
Please don't hack around this in tests. WARN_ON() is only meant to be used to
indicate kernel bugs. It should never be reachable by userspace. I'm seeing
the same WARNING when fuzzing with syzkaller (see below). If it's supposed to
be reachable by userspace, then it *must* be removed, or perhaps replaced with
pr_warn_ratelimited() with a message that is actually understandable, like
"process 'foo' mixes buffered I/O with direct I/O".
WARNING: CPU: 2 PID: 27399 at fs/direct-io.c:293
dio_complete+0x532/0x7e0 fs/direct-io.c:293
Kernel panic - not syncing: panic_on_warn set ...
CPU: 2 PID: 27399 Comm: syz-executor0 Not tainted
4.14.0-rc7-00174-g2d6349944d96 #1
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
1.10.3-20171021_125229-anatol 04/01/2014
Call Trace:
__dump_stack lib/dump_stack.c:17 [inline]
dump_stack+0x115/0x1da lib/dump_stack.c:53
panic+0x1b4/0x39c kernel/panic.c:181
__warn+0x1bf/0x1d4 kernel/panic.c:542
report_bug+0x23f/0x2c0 lib/bug.c:184
fixup_bug+0x3f/0x90 arch/x86/kernel/traps.c:178
do_trap_no_signal arch/x86/kernel/traps.c:212 [inline]
do_trap+0x260/0x390 arch/x86/kernel/traps.c:261
do_error_trap+0x11c/0x350 arch/x86/kernel/traps.c:298
do_invalid_op+0x1b/0x20 arch/x86/kernel/traps.c:311
invalid_op+0x18/0x20 arch/x86/entry/entry_64.S:906
RIP: 0010:dio_complete+0x532/0x7e0 fs/direct-io.c:293
RSP: 0018:ffff880039dcf208 EFLAGS: 00010212
RAX: 0000000000010000 RBX: ffff880061a1f040 RCX: 0000000000000ebd
RDX: ffffffff816b97f2 RSI: ffffc90000696000 RDI: ffffed00073b9e36
RBP: ffff880039dcf250 R08: ffff88007ffd709c R09: ffff880037874640
R10: 00000000000002e7 R11: ffff88007ffd709d R12: 0000000000000200
R13: 0000000000000200 R14: ffff8800593cf8f0 R15: ffffffff898005d0
do_blockdev_direct_IO fs/direct-io.c:1374 [inline]
__blockdev_direct_IO+0x46b9/0x8a70 fs/direct-io.c:1400
ext4_direct_IO_write fs/ext4/inode.c:3685 [inline]
ext4_direct_IO+0x98e/0x1950 fs/ext4/inode.c:3807
generic_file_direct_write+0x1e6/0x440 mm/filemap.c:2928
__generic_file_write_iter+0x21f/0x5b0 mm/filemap.c:3107
ext4_file_write_iter+0x5c2/0x10a0 fs/ext4/file.c:264
call_write_iter include/linux/fs.h:1771 [inline]
new_sync_write fs/read_write.c:469 [inline]
__vfs_write+0x681/0x970 fs/read_write.c:482
vfs_write+0x18b/0x480 fs/read_write.c:544
SYSC_write fs/read_write.c:589 [inline]
SyS_write+0xef/0x230 fs/read_write.c:581
entry_SYSCALL_64_fastpath+0x1f/0xbe
RIP: 0033:0x4585c9
RSP: 002b:00007ff87eff2bd8 EFLAGS: 00000216 ORIG_RAX: 0000000000000001
RAX: ffffffffffffffda RBX: 0000000000738020 RCX: 00000000004585c9
RDX: 0000000000000200 RSI: 0000000020010000 RDI: 0000000000000015
RBP: 0000000000000046 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000216 R12: 00000000006d1048
R13: 00000000ffffffff R14: 00007ff87eff36bc R15: 0000000000000000
Dumping ftrace buffer:
(ftrace buffer empty)
Kernel Offset: 0x8000000 from 0xffffffff81000000 (relocation range:
0xffffffff80000000-0xffffffffbfffffff)
Rebooting in 86400 seconds..
