2017-09-18 14:56:20

by Abdul Haleem

[permalink] [raw]
Subject: [linux-next][XFS][trinity] WARNING: CPU: 32 PID: 31369 at fs/iomap.c:993

Hi,

A warning is triggered from:

file fs/iomap.c in function iomap_dio_rw

if (ret)
goto out_free_dio;

ret = invalidate_inode_pages2_range(mapping,
start >> PAGE_SHIFT, end >> PAGE_SHIFT);
>> WARN_ON_ONCE(ret);
ret = 0;

inode_dio_begin(inode);

Machine Type: Power 7 PowerVM LPAR
Kernel : 4.13.0-next-20170915
gcc: 4.8.5
Test: trinity fuzzer


dmesg:
------------[ cut here ]------------
WARNING: CPU: 32 PID: 31369 at fs/iomap.c:993 .iomap_dio_rw+0x470/0x480
Modules linked in: dlci(E) 8021q(E) garp(E) mrp(E) af_key(E)
ieee802154_socket(E) ieee802154(E) rpcrdma(E) ib_isert(E)
iscsi_target_mod(E) ib_iser(E) libiscsi(E) ib_srpt(E) target_core_mod(E)
ib_srp(E) hidp(E) ib_ipoib(E) cmtp(E) kernelcapi(E) rdma_ucm(E)
ib_ucm(E) bnep(E) ib_uverbs(E) rfcomm(E) bluetooth(E) ib_umad(E)
rdma_cm(E) ecdh_generic(E) rfkill(E) ib_cm(E) iw_cm(E) pptp(E) gre(E)
l2tp_ppp(E) l2tp_netlink(E) l2tp_core(E) ip6_udp_tunnel(E) udp_tunnel(E)
pppoe(E) pppox(E) ppp_generic(E) slhc(E) crypto_user(E) ib_core(E)
nfnetlink(E) scsi_transport_iscsi(E) atm(E) sctp(E) dccp_ipv4(E)
netlink_diag(E) dccp_diag(E) ip6table_filter(E) af_packet_diag(E)
unix_diag(E) tcp_diag(E) udp_diag(E) ebtable_filter(E) bridge(E) sg(E)
ibmveth(E) rpadlpar_io(E) loop(E) xt_CHECKSUM(E) iptable_mangle(E)
ipt_MASQUERADE(E) nf_nat_masquerade_ipv4(E) iptable_nat(E)
nf_nat_ipv4(E) nf_nat(E) nf_conntrack_ipv4(E) nf_defrag_ipv4(E)
xt_conntrack(E) nf_conntrack(E) ipt_REJECT(E) nf_reject_ipv4(E) tun(E)
stp(E) llc(E) rpaphp(E) kvm_pr(E) kvm(E) ebtables(E) ip6_tables(E)
dccp(E) inet_diag(E) iptable_filter(E) nfsd(E) auth_rpcgss(E) nfs_acl(E)
lockd(E) grace(E) sunrpc(E) binfmt_misc(E) ip_tables(E) ext4(E)
mbcache(E) jbd2(E) sd_mod(E) ibmvscsi(E) scsi_transport_srp(E) [last
unloaded: netlink_diag]
CPU: 32 PID: 31369 Comm: trinity-c133 Tainted: G E
4.13.0-next-20170915-autotest #1
task: c0000009f4149d80 task.stack: c000000546920000
NIP: c0000000003aac40 LR: c0000000003aa9e8 CTR: 0000000000000000
REGS: c000000546923630 TRAP: 0700 Tainted: G E
(4.13.0-next-20170915-autotest)
MSR: 800000000282b032 <SF,VEC,VSX,EE,FP,ME,IR,DR,RI> CR: 28004428
XER: 20000000
CFAR: c0000000003aa9f0 SOFTE: 1
GPR00: c0000000003aa9e8 c0000005469238b0 c000000001453b00
fffffffffffffff0
GPR04: 0000000000000000 0000000000000000 0000000000000000
0000000000000000
GPR08: 0000000000000000 00000000ffffffff 0000000000000000
0000000000000000
GPR12: 0000000028004422 c00000000e945000 0000000000000000
0000000010030a00
GPR16: 0000000010030bc8 0000000000000000 0000000000000000
0000000000000000
GPR20: 0000000000000000 0000000000000000 c0000013ebcc16a0
0000000000000010
GPR24: c00000099ec0c2d0 c000000000a49168 c00000099ec0c158
c000000546923b70
GPR28: c000000546923d40 0000000000000014 0000000000000000
c0000013ebcc1680
NIP [c0000000003aac40] .iomap_dio_rw+0x470/0x480
LR [c0000000003aa9e8] .iomap_dio_rw+0x218/0x480
Call Trace:
[c0000005469238b0] [c0000000003aa9e8] .iomap_dio_rw+0x218/0x480
(unreliable)
[c0000005469239d0] [c0000000004639c8] .xfs_file_dio_aio_read+0x88/0x160
[c000000546923a70] [c000000000463f44] .xfs_file_read_iter+0x104/0x120
[c000000546923b00] [c0000000003248f0] .do_iter_readv_writev+0x190/0x1c0
[c000000546923bb0] [c000000000325d90] .do_iter_read+0xf0/0x280
[c000000546923c50] [c00000000032858c] .vfs_readv+0x6c/0xa0
[c000000546923d90] [c0000000003287b8] .do_preadv+0xd8/0x120
[c000000546923e30] [c00000000000b184] system_call+0x58/0x6c
Instruction dump:
7c0af000 40c20010 7c60492d 40c2fff0 7c0004ac 4bfffe90 60000000 60000000
3be0fdef 4bfffc0c 3be0fff4 4bfffc04 <0fe00000> 4bfffdb0 00000000
00000000
---[ end trace bd674540a2bf235b ]---


--
Regard's

Abdul Haleem
IBM Linux Technology Centre



Attachments:
p7-vm-config (137.77 kB)

2017-09-18 15:27:09

by Christoph Hellwig

[permalink] [raw]
Subject: Re: [linux-next][XFS][trinity] WARNING: CPU: 32 PID: 31369 at fs/iomap.c:993

On Mon, Sep 18, 2017 at 08:26:05PM +0530, Abdul Haleem wrote:
> Hi,
>
> A warning is triggered from:
>
> file fs/iomap.c in function iomap_dio_rw
>
> if (ret)
> goto out_free_dio;
>
> ret = invalidate_inode_pages2_range(mapping,
> start >> PAGE_SHIFT, end >> PAGE_SHIFT);
> >> WARN_ON_ONCE(ret);
> ret = 0;
>
> inode_dio_begin(inode);

This is expected and an indication of a problematic workload - which
may be triggered by a fuzzer.

2017-09-18 15:29:02

by Jens Axboe

[permalink] [raw]
Subject: Re: [linux-next][XFS][trinity] WARNING: CPU: 32 PID: 31369 at fs/iomap.c:993

On 09/18/2017 09:27 AM, Christoph Hellwig wrote:
> On Mon, Sep 18, 2017 at 08:26:05PM +0530, Abdul Haleem wrote:
>> Hi,
>>
>> A warning is triggered from:
>>
>> file fs/iomap.c in function iomap_dio_rw
>>
>> if (ret)
>> goto out_free_dio;
>>
>> ret = invalidate_inode_pages2_range(mapping,
>> start >> PAGE_SHIFT, end >> PAGE_SHIFT);
>>>> WARN_ON_ONCE(ret);
>> ret = 0;
>>
>> inode_dio_begin(inode);
>
> This is expected and an indication of a problematic workload - which
> may be triggered by a fuzzer.

If it's expected, why don't we kill the WARN_ON_ONCE()? I get it all
the time running xfstests as well.

--
Jens Axboe

2017-09-18 15:39:50

by Christoph Hellwig

[permalink] [raw]
Subject: Re: [linux-next][XFS][trinity] WARNING: CPU: 32 PID: 31369 at fs/iomap.c:993

On Mon, Sep 18, 2017 at 09:28:55AM -0600, Jens Axboe wrote:
> If it's expected, why don't we kill the WARN_ON_ONCE()? I get it all
> the time running xfstests as well.

Dave insisted on it to decourage users/applications from mixing
mmap and direct I/O.

In many ways a tracepoint might be the better way to diagnose these.

2017-09-18 15:43:35

by Al Viro

[permalink] [raw]
Subject: Re: [linux-next][XFS][trinity] WARNING: CPU: 32 PID: 31369 at fs/iomap.c:993

On Mon, Sep 18, 2017 at 05:39:47PM +0200, Christoph Hellwig wrote:
> On Mon, Sep 18, 2017 at 09:28:55AM -0600, Jens Axboe wrote:
> > If it's expected, why don't we kill the WARN_ON_ONCE()? I get it all
> > the time running xfstests as well.
>
> Dave insisted on it to decourage users/applications from mixing
> mmap and direct I/O.
>
> In many ways a tracepoint might be the better way to diagnose these.

sysctl suppressing those two, perhaps?

2017-09-18 15:51:35

by Jens Axboe

[permalink] [raw]
Subject: Re: [linux-next][XFS][trinity] WARNING: CPU: 32 PID: 31369 at fs/iomap.c:993

On 09/18/2017 09:43 AM, Al Viro wrote:
> On Mon, Sep 18, 2017 at 05:39:47PM +0200, Christoph Hellwig wrote:
>> On Mon, Sep 18, 2017 at 09:28:55AM -0600, Jens Axboe wrote:
>>> If it's expected, why don't we kill the WARN_ON_ONCE()? I get it all
>>> the time running xfstests as well.
>>
>> Dave insisted on it to decourage users/applications from mixing
>> mmap and direct I/O.
>>
>> In many ways a tracepoint might be the better way to diagnose these.
>
> sysctl suppressing those two, perhaps?

I'd rather just make it a trace point, but don't care too much.

The code doesn't even have a comment as to why that WARN_ON() is
there or expected. Seems pretty sloppy to me, not a great way
to "discourage" users to mix mmap/dio.

--
Jens Axboe

2017-09-18 21:31:49

by Dave Chinner

[permalink] [raw]
Subject: Re: [linux-next][XFS][trinity] WARNING: CPU: 32 PID: 31369 at fs/iomap.c:993

On Mon, Sep 18, 2017 at 09:28:55AM -0600, Jens Axboe wrote:
> On 09/18/2017 09:27 AM, Christoph Hellwig wrote:
> > On Mon, Sep 18, 2017 at 08:26:05PM +0530, Abdul Haleem wrote:
> >> Hi,
> >>
> >> A warning is triggered from:
> >>
> >> file fs/iomap.c in function iomap_dio_rw
> >>
> >> if (ret)
> >> goto out_free_dio;
> >>
> >> ret = invalidate_inode_pages2_range(mapping,
> >> start >> PAGE_SHIFT, end >> PAGE_SHIFT);
> >>>> WARN_ON_ONCE(ret);
> >> ret = 0;
> >>
> >> inode_dio_begin(inode);
> >
> > This is expected and an indication of a problematic workload - which
> > may be triggered by a fuzzer.
>
> If it's expected, why don't we kill the WARN_ON_ONCE()? I get it all
> the time running xfstests as well.

Because when a user reports a data corruption, the only evidence we
have that they are running an app that does something stupid is this
warning in their syslogs. Tracepoints are not useful for replacing
warnings about data corruption vectors being triggered.

It needs to be on by default, bu tI'm sure we can wrap it with
something like an xfs_alert_tag() type of construct so the tag can
be set in /proc/fs/xfs/panic_mask to suppress it if testers so
desire.

Cheers,

Dave.

--
Dave Chinner
[email protected]

2017-09-18 21:53:35

by Dave Chinner

[permalink] [raw]
Subject: Re: [linux-next][XFS][trinity] WARNING: CPU: 32 PID: 31369 at fs/iomap.c:993

On Mon, Sep 18, 2017 at 09:51:29AM -0600, Jens Axboe wrote:
> On 09/18/2017 09:43 AM, Al Viro wrote:
> > On Mon, Sep 18, 2017 at 05:39:47PM +0200, Christoph Hellwig wrote:
> >> On Mon, Sep 18, 2017 at 09:28:55AM -0600, Jens Axboe wrote:
> >>> If it's expected, why don't we kill the WARN_ON_ONCE()? I get it all
> >>> the time running xfstests as well.
> >>
> >> Dave insisted on it to decourage users/applications from mixing
> >> mmap and direct I/O.
> >>
> >> In many ways a tracepoint might be the better way to diagnose these.
> >
> > sysctl suppressing those two, perhaps?
>
> I'd rather just make it a trace point, but don't care too much.
>
> The code doesn't even have a comment as to why that WARN_ON() is
> there or expected.

The big comment about how bad cache invalidation failures are is on
the second, post-io invocation of the page cache flush. That's the
failure that exposes the data coherency problem to userspace:

/*
* Try again to invalidate clean pages which might have been cached by
* non-direct readahead, or faulted in by get_user_pages() if the source
* of the write was an mmap'ed region of the file we're writing. Either
* one is a pretty crazy thing to do, so we don't support it 100%. If
* this invalidation fails, tough, the write still worked...
*/
if (iov_iter_rw(iter) == WRITE) {
int err = invalidate_inode_pages2_range(mapping,
start >> PAGE_SHIFT, end >> PAGE_SHIFT);
WARN_ON_ONCE(err);
}

IOWs, the first warning is a "bad things might be about to
happen" warning, the second is "bad things have happened".

> Seems pretty sloppy to me, not a great way
> to "discourage" users to mix mmap/dio.

Again, it has nothing to do with "discouraging users" and everything
about post-bug report problem triage.

Yes, the first invalidation should also have a comment like the post
IO invalidation - the comment probably got dropped and not noticed
when the changeover from internal XFS code to generic iomap code was
made...

Cheers,

Dave.
--
Dave Chinner
[email protected]

2017-09-18 22:01:02

by Eric Sandeen

[permalink] [raw]
Subject: Re: [linux-next][XFS][trinity] WARNING: CPU: 32 PID: 31369 at fs/iomap.c:993

On 9/18/17 4:31 PM, Dave Chinner wrote:
> On Mon, Sep 18, 2017 at 09:28:55AM -0600, Jens Axboe wrote:
>> On 09/18/2017 09:27 AM, Christoph Hellwig wrote:
>>> On Mon, Sep 18, 2017 at 08:26:05PM +0530, Abdul Haleem wrote:
>>>> Hi,
>>>>
>>>> A warning is triggered from:
>>>>
>>>> file fs/iomap.c in function iomap_dio_rw
>>>>
>>>> if (ret)
>>>> goto out_free_dio;
>>>>
>>>> ret = invalidate_inode_pages2_range(mapping,
>>>> start >> PAGE_SHIFT, end >> PAGE_SHIFT);
>>>>>> WARN_ON_ONCE(ret);
>>>> ret = 0;
>>>>
>>>> inode_dio_begin(inode);
>>>
>>> This is expected and an indication of a problematic workload - which
>>> may be triggered by a fuzzer.
>>
>> If it's expected, why don't we kill the WARN_ON_ONCE()? I get it all
>> the time running xfstests as well.
>
> Because when a user reports a data corruption, the only evidence we
> have that they are running an app that does something stupid is this
> warning in their syslogs. Tracepoints are not useful for replacing
> warnings about data corruption vectors being triggered.

Is the full WARN_ON spew really helpful to us, though? Certainly
the user has no idea what it means, and will come away terrified
but none the wiser.

Would a more informative printk_once() still give us the evidence
without the ZOMG I THINK I OOPSED that a WARN_ON produces? Or do we
want/need the backtrace?

-Eric

> It needs to be on by default, bu tI'm sure we can wrap it with
> something like an xfs_alert_tag() type of construct so the tag can
> be set in /proc/fs/xfs/panic_mask to suppress it if testers so
> desire.
>
> Cheers,
>
> Dave.
>

2017-09-18 22:04:29

by Darrick J. Wong

[permalink] [raw]
Subject: Re: [linux-next][XFS][trinity] WARNING: CPU: 32 PID: 31369 at fs/iomap.c:993

On Mon, Sep 18, 2017 at 05:00:58PM -0500, Eric Sandeen wrote:
> On 9/18/17 4:31 PM, Dave Chinner wrote:
> > On Mon, Sep 18, 2017 at 09:28:55AM -0600, Jens Axboe wrote:
> >> On 09/18/2017 09:27 AM, Christoph Hellwig wrote:
> >>> On Mon, Sep 18, 2017 at 08:26:05PM +0530, Abdul Haleem wrote:
> >>>> Hi,
> >>>>
> >>>> A warning is triggered from:
> >>>>
> >>>> file fs/iomap.c in function iomap_dio_rw
> >>>>
> >>>> if (ret)
> >>>> goto out_free_dio;
> >>>>
> >>>> ret = invalidate_inode_pages2_range(mapping,
> >>>> start >> PAGE_SHIFT, end >> PAGE_SHIFT);
> >>>>>> WARN_ON_ONCE(ret);
> >>>> ret = 0;
> >>>>
> >>>> inode_dio_begin(inode);
> >>>
> >>> This is expected and an indication of a problematic workload - which
> >>> may be triggered by a fuzzer.
> >>
> >> If it's expected, why don't we kill the WARN_ON_ONCE()? I get it all
> >> the time running xfstests as well.
> >
> > Because when a user reports a data corruption, the only evidence we
> > have that they are running an app that does something stupid is this
> > warning in their syslogs. Tracepoints are not useful for replacing
> > warnings about data corruption vectors being triggered.
>
> Is the full WARN_ON spew really helpful to us, though? Certainly
> the user has no idea what it means, and will come away terrified
> but none the wiser.
>
> Would a more informative printk_once() still give us the evidence
> without the ZOMG I THINK I OOPSED that a WARN_ON produces? Or do we
> want/need the backtrace?

Maybe we could state a little more directly what's going on:

if (err)
printk_once(KERN_INFO "Urk, collision detected between direct IO and page cache, YHL. HAND.\n"); ?

8-)

--D

>
> -Eric
>
> > It needs to be on by default, bu tI'm sure we can wrap it with
> > something like an xfs_alert_tag() type of construct so the tag can
> > be set in /proc/fs/xfs/panic_mask to suppress it if testers so
> > desire.
> >
> > Cheers,
> >
> > Dave.
> >
> --
> To unsubscribe from this list: send the line "unsubscribe linux-next" in
> the body of a message to [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html

2017-09-18 22:05:43

by Dave Chinner

[permalink] [raw]
Subject: Re: [linux-next][XFS][trinity] WARNING: CPU: 32 PID: 31369 at fs/iomap.c:993

On Mon, Sep 18, 2017 at 05:00:58PM -0500, Eric Sandeen wrote:
> On 9/18/17 4:31 PM, Dave Chinner wrote:
> > On Mon, Sep 18, 2017 at 09:28:55AM -0600, Jens Axboe wrote:
> >> On 09/18/2017 09:27 AM, Christoph Hellwig wrote:
> >>> On Mon, Sep 18, 2017 at 08:26:05PM +0530, Abdul Haleem wrote:
> >>>> Hi,
> >>>>
> >>>> A warning is triggered from:
> >>>>
> >>>> file fs/iomap.c in function iomap_dio_rw
> >>>>
> >>>> if (ret)
> >>>> goto out_free_dio;
> >>>>
> >>>> ret = invalidate_inode_pages2_range(mapping,
> >>>> start >> PAGE_SHIFT, end >> PAGE_SHIFT);
> >>>>>> WARN_ON_ONCE(ret);
> >>>> ret = 0;
> >>>>
> >>>> inode_dio_begin(inode);
> >>>
> >>> This is expected and an indication of a problematic workload - which
> >>> may be triggered by a fuzzer.
> >>
> >> If it's expected, why don't we kill the WARN_ON_ONCE()? I get it all
> >> the time running xfstests as well.
> >
> > Because when a user reports a data corruption, the only evidence we
> > have that they are running an app that does something stupid is this
> > warning in their syslogs. Tracepoints are not useful for replacing
> > warnings about data corruption vectors being triggered.
>
> Is the full WARN_ON spew really helpful to us, though? Certainly
> the user has no idea what it means, and will come away terrified
> but none the wiser.
>
> Would a more informative printk_once() still give us the evidence
> without the ZOMG I THINK I OOPSED that a WARN_ON produces? Or do we
> want/need the backtrace?

backtrace is actually useful - that's how I recently learnt that
splice now supports direct IO.....

Cheers,

Dave.
--
Dave Chinner
[email protected]