2018-10-29 17:57:12

by Julien Thierry

[permalink] [raw]
Subject: [PATCH] SUNRPC: Fix iter_iov_*vec warnings

While booting linux-next on Juno with rootfs over NFS, the following
warning is spammed on kernel log:

[ 16.988190] WARNING: CPU: 1 PID: 680 at lib/iov_iter.c:1082 iov_iter_kvec+0x20/0x40
[ 16.995776] Modules linked in:
[ 16.998801] CPU: 1 PID: 680 Comm: kworker/u13:0 Not tainted 4.19.0-next-20181029 #2238
[ 17.006640] Hardware name: ARM Juno development board (r0) (DT)
[ 17.012505] Workqueue: xprtiod xs_stream_data_receive_workfn
[ 17.018108] pstate: 00000005 (nzcv daif -PAN -UAO)
[ 17.022851] pc : iov_iter_kvec+0x20/0x40
[ 17.026733] lr : xs_stream_data_receive+0x194/0x378
[ 17.031559] sp : ffff00000b033ce0
[ 17.034836] x29: ffff00000b033ce0 x28: 0000000000000000
[ 17.040095] x27: ffff8009760b9870 x26: ffff00000917e1c8
[ 17.045352] x25: 0000000000000000 x24: ffff800976a91598
[ 17.050610] x23: ffff000009169000 x22: ffff8009775f0000
[ 17.055867] x21: 000000000000000c x20: ffff800976a91578
[ 17.061124] x19: ffff800976a91000 x18: 0000000000000000
[ 17.066381] x17: 0000000000000000 x16: 0000000000000000
[ 17.071639] x15: 0000000000000400 x14: 0000000000000400
[ 17.076896] x13: 0000000000000400 x12: 0000000000002f28
[ 17.082153] x11: 0000000000000000 x10: 0000000000000960
[ 17.087410] x9 : ffff00000b033d50 x8 : fefefefefefefeff
[ 17.092667] x7 : ffff80097ff9d380 x6 : 0000000000000000
[ 17.097924] x5 : 00646f6974727078 x4 : 000000000000000c
[ 17.103181] x3 : 0000000000000001 x2 : ffff00000b033d30
[ 17.108438] x1 : 0000000000000002 x0 : ffff00000b033d50
[ 17.113695] Call trace:
[ 17.116115] iov_iter_kvec+0x20/0x40
[ 17.119652] xs_stream_data_receive_workfn+0x10/0x18
[ 17.124568] process_one_work+0x1c8/0x318
[ 17.128535] worker_thread+0x48/0x428
[ 17.132158] kthread+0xf8/0x128
[ 17.135266] ret_from_fork+0x10/0x18
[ 17.138801] ---[ end trace 65cbcd2ddaeef59e ]---

This is likely a clash between the recent addition of vector iterators to
SUNRPC and the recent
commit aa563d7bca6e882ec2bdae24603c8f016401a144 ("iov_iter: Separate
type from direction and use accessor functions") which slightly changes
the usage of those iterators by splitting type and direction.

Fix this by not including type in the direction of the operation.

Fixes: 277e4ab7d530bf287e02b65cfcd3ea8f489784f6 ("SUNRPC: Simplify TCP
receive code by switching to using iterators")

Signed-off-by: Julien Thierry <[email protected]>
Cc: Trond Myklebust <[email protected]>
Cc: Anna Schumaker <[email protected]>
Cc: "J. Bruce Fields" <[email protected]>
Cc: Jeff Layton <[email protected]>
Cc: "David S. Miller" <[email protected]>
Cc: [email protected]
Cc: [email protected]
---
net/sunrpc/xprtsock.c | 4 ++--
1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/net/sunrpc/xprtsock.c b/net/sunrpc/xprtsock.c
index 1b51e04..ae77c71 100644
--- a/net/sunrpc/xprtsock.c
+++ b/net/sunrpc/xprtsock.c
@@ -361,7 +361,7 @@ static void xs_free_peer_addresses(struct rpc_xprt *xprt)
xs_read_kvec(struct socket *sock, struct msghdr *msg, int flags,
struct kvec *kvec, size_t count, size_t seek)
{
- iov_iter_kvec(&msg->msg_iter, READ | ITER_KVEC, kvec, 1, count);
+ iov_iter_kvec(&msg->msg_iter, READ, kvec, 1, count);
return xs_sock_recvmsg(sock, msg, flags, seek);
}

@@ -370,7 +370,7 @@ static void xs_free_peer_addresses(struct rpc_xprt *xprt)
struct bio_vec *bvec, unsigned long nr, size_t count,
size_t seek)
{
- iov_iter_bvec(&msg->msg_iter, READ | ITER_BVEC, bvec, nr, count);
+ iov_iter_bvec(&msg->msg_iter, READ, bvec, nr, count);
return xs_sock_recvmsg(sock, msg, flags, seek);
}

--
1.9.1



2018-10-29 18:04:57

by Trond Myklebust

[permalink] [raw]
Subject: Re: [PATCH] SUNRPC: Fix iter_iov_*vec warnings

Cc: Al, since this wants to go through his pull request (the RPC code
has already been merged).

On Mon, 2018-10-29 at 17:55 +0000, Julien Thierry wrote:
> While booting linux-next on Juno with rootfs over NFS, the following
> warning is spammed on kernel log:
>
> [ 16.988190] WARNING: CPU: 1 PID: 680 at lib/iov_iter.c:1082
> iov_iter_kvec+0x20/0x40
> [ 16.995776] Modules linked in:
> [ 16.998801] CPU: 1 PID: 680 Comm: kworker/u13:0 Not tainted
> 4.19.0-next-20181029 #2238
> [ 17.006640] Hardware name: ARM Juno development board (r0) (DT)
> [ 17.012505] Workqueue: xprtiod xs_stream_data_receive_workfn
> [ 17.018108] pstate: 00000005 (nzcv daif -PAN -UAO)
> [ 17.022851] pc : iov_iter_kvec+0x20/0x40
> [ 17.026733] lr : xs_stream_data_receive+0x194/0x378
> [ 17.031559] sp : ffff00000b033ce0
> [ 17.034836] x29: ffff00000b033ce0 x28: 0000000000000000
> [ 17.040095] x27: ffff8009760b9870 x26: ffff00000917e1c8
> [ 17.045352] x25: 0000000000000000 x24: ffff800976a91598
> [ 17.050610] x23: ffff000009169000 x22: ffff8009775f0000
> [ 17.055867] x21: 000000000000000c x20: ffff800976a91578
> [ 17.061124] x19: ffff800976a91000 x18: 0000000000000000
> [ 17.066381] x17: 0000000000000000 x16: 0000000000000000
> [ 17.071639] x15: 0000000000000400 x14: 0000000000000400
> [ 17.076896] x13: 0000000000000400 x12: 0000000000002f28
> [ 17.082153] x11: 0000000000000000 x10: 0000000000000960
> [ 17.087410] x9 : ffff00000b033d50 x8 : fefefefefefefeff
> [ 17.092667] x7 : ffff80097ff9d380 x6 : 0000000000000000
> [ 17.097924] x5 : 00646f6974727078 x4 : 000000000000000c
> [ 17.103181] x3 : 0000000000000001 x2 : ffff00000b033d30
> [ 17.108438] x1 : 0000000000000002 x0 : ffff00000b033d50
> [ 17.113695] Call trace:
> [ 17.116115] iov_iter_kvec+0x20/0x40
> [ 17.119652] xs_stream_data_receive_workfn+0x10/0x18
> [ 17.124568] process_one_work+0x1c8/0x318
> [ 17.128535] worker_thread+0x48/0x428
> [ 17.132158] kthread+0xf8/0x128
> [ 17.135266] ret_from_fork+0x10/0x18
> [ 17.138801] ---[ end trace 65cbcd2ddaeef59e ]---
>
> This is likely a clash between the recent addition of vector
> iterators to
> SUNRPC and the recent
> commit aa563d7bca6e882ec2bdae24603c8f016401a144 ("iov_iter: Separate
> type from direction and use accessor functions") which slightly
> changes
> the usage of those iterators by splitting type and direction.
>
> Fix this by not including type in the direction of the operation.
>
> Fixes: 277e4ab7d530bf287e02b65cfcd3ea8f489784f6 ("SUNRPC: Simplify
> TCP
> receive code by switching to using iterators")
>
> Signed-off-by: Julien Thierry <[email protected]>
> Cc: Trond Myklebust <[email protected]>
> Cc: Anna Schumaker <[email protected]>
> Cc: "J. Bruce Fields" <[email protected]>
> Cc: Jeff Layton <[email protected]>
> Cc: "David S. Miller" <[email protected]>
> Cc: [email protected]
> Cc: [email protected]
> ---
> net/sunrpc/xprtsock.c | 4 ++--
> 1 file changed, 2 insertions(+), 2 deletions(-)
>
> diff --git a/net/sunrpc/xprtsock.c b/net/sunrpc/xprtsock.c
> index 1b51e04..ae77c71 100644
> --- a/net/sunrpc/xprtsock.c
> +++ b/net/sunrpc/xprtsock.c
> @@ -361,7 +361,7 @@ static void xs_free_peer_addresses(struct
> rpc_xprt *xprt)
> xs_read_kvec(struct socket *sock, struct msghdr *msg, int flags,
> struct kvec *kvec, size_t count, size_t seek)
> {
> - iov_iter_kvec(&msg->msg_iter, READ | ITER_KVEC, kvec, 1,
> count);
> + iov_iter_kvec(&msg->msg_iter, READ, kvec, 1, count);
> return xs_sock_recvmsg(sock, msg, flags, seek);
> }
>
> @@ -370,7 +370,7 @@ static void xs_free_peer_addresses(struct
> rpc_xprt *xprt)
> struct bio_vec *bvec, unsigned long nr, size_t count,
> size_t seek)
> {
> - iov_iter_bvec(&msg->msg_iter, READ | ITER_BVEC, bvec, nr,
> count);
> + iov_iter_bvec(&msg->msg_iter, READ, bvec, nr, count);
> return xs_sock_recvmsg(sock, msg, flags, seek);
> }
>
--
Trond Myklebust
CTO, Hammerspace Inc
4300 El Camino Real, Suite 105
Los Altos, CA 94022
http://www.hammer.space


2018-11-01 01:05:55

by Chen, Rong A

[permalink] [raw]
Subject: [LKP] [SUNRPC] 9502426546: kernel_BUG_at_lib/iov_iter.c

FYI, we noticed the following commit (built with gcc-7):

commit: 950242654634fb437dc5848a23c970589e62b088 ("[PATCH] SUNRPC: Fix iter_iov_*vec warnings")
url: https://github.com/0day-ci/linux/commits/Julien-Thierry/SUNRPC-Fix-iter_iov_-vec-warnings/20181030-020648
base: git://git.linux-nfs.org/projects/trondmy/linux-nfs.git linux-next

in testcase: boot

on test machine: qemu-system-x86_64 -enable-kvm -cpu host -smp 2 -m 4G

caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):


+------------------------------------------+------------+------------+
| | 86bbd7422a | 9502426546 |
+------------------------------------------+------------+------------+
| boot_successes | 4 | 2 |
| boot_failures | 0 | 4 |
| kernel_BUG_at_lib/iov_iter.c | 0 | 4 |
| invalid_opcode:#[##] | 0 | 4 |
| RIP:iov_iter_kvec | 0 | 4 |
| Kernel_panic-not_syncing:Fatal_exception | 0 | 4 |
+------------------------------------------+------------+------------+



[ 192.691114] kernel BUG at lib/iov_iter.c:1067!
[ 192.706864] invalid opcode: 0000 [#1] PREEMPT DEBUG_PAGEALLOC PTI
[ 192.722744] CPU: 0 PID: 395 Comm: kworker/u3:1 Not tainted 4.19.0-rc6-00095-g9502426 #1
[ 192.734956] Workqueue: xprtiod xs_stream_data_receive_workfn
[ 192.743807] RIP: 0010:iov_iter_kvec+0xa/0x30
[ 192.753616] Code: eb 0e 48 8b 56 08 48 29 ca 48 39 d0 48 0f 47 c2 5d c3 0f 1f 40 00 66 2e 0f 1f 84 00 00 00 00 00 40 f6 c6 02 75 06 55 48 89 e5 <0f> 0b 89 37 48 89 57 18 48 89 4f 20 48 c7 47 08 00 00 00 00 4c 89
[ 192.791830] RSP: 0018:ffff88012606fd00 EFLAGS: 00010246
[ 192.800611] RAX: ffff880129494d20 RBX: ffff880129494548 RCX: 0000000000000001
[ 192.812147] RDX: ffff88012606fd60 RSI: 0000000000000000 RDI: ffff88012606fd80
[ 192.823818] RBP: ffff88012606fd00 R08: 000000000000000c R09: 0000000000000001
[ 192.835476] R10: ffff88012606fdf8 R11: 0000000000000000 R12: 000000000000000c
[ 192.847111] R13: ffff88012606fd70 R14: ffff8801241f4040 R15: 0000000000000000
[ 192.863641] FS: 0000000000000000(0000) GS:ffffffff8263d000(0000) knlGS:0000000000000000
[ 192.876793] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 192.886211] CR2: 00005632b76b7ff0 CR3: 000000000261c001 CR4: 00000000000206b0
[ 192.897906] Call Trace:
[ 192.902089] xs_read_stream+0x9b/0x820
[ 192.910023] ? preempt_count_sub+0x58/0x70
[ 192.916866] ? __mutex_lock+0x148/0x580
[ 192.923216] xs_stream_data_receive_workfn+0x51/0x100
[ 192.931544] process_one_work+0x27d/0x490
[ 192.938124] worker_thread+0x228/0x3b0
[ 192.944376] ? __kthread_parkme+0x51/0x90
[ 192.950930] kthread+0x132/0x140
[ 192.956401] ? process_one_work+0x490/0x490
[ 192.963302] ? __kthread_create_on_node+0x1b0/0x1b0
[ 192.971404] ret_from_fork+0x3a/0x50
[ 192.981486] ---[ end trace e16b504e978b7121 ]---


To reproduce:

git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email



Thanks,
lkp


Attachments:
(No filename) (3.23 kB)
config-4.19.0-rc6-00095-g9502426 (106.26 kB)
job-script (4.37 kB)
dmesg.xz (14.00 kB)
Download all attachments