2022-12-30 03:43:13

by Pengfei Xu

[permalink] [raw]
Subject: Update bisect info and new repro code for "[syzbot] WARNING in _copy_from_iter"

Hi Viro,

Related email link:
https://lore.kernel.org/lkml/Y5WlLoCBcHbfKBD5@ZenIV/

syzbot link:
https://syzkaller.appspot.com/bug?id=4694bd1c1c0019f067af5b6e14e8ef02431b6b34


I reproduced on TGL-H with v6.2-rc1 kernel.

All reproduced code bisect info are in link:
https://github.com/xupengfe/syzkaller_logs/tree/main/221228_010310__copy_from_iter

I hope it's helpful.

Thanks!
BR.


2023-01-05 02:26:09

by Pengfei Xu

[permalink] [raw]
Subject: Re: Update bisect info and new repro code for "[syzbot] WARNING in _copy_from_iter"

Hi Viro,

It's a soft remind: "_copy_from_iter" WARNING issue was still reproduced
in v6.2-rc2 mainline kernel in guest.
"
[ 29.804009] sg_write: data in/out 131036/42 bytes for SCSI command 0xff-- guessing data in;
[ 29.804009] program repro not setting count and/or reply_len properly
[ 29.806580] ------------[ cut here ]------------
[ 29.807212] WARNING: CPU: 0 PID: 514 at lib/iov_iter.c:629 _copy_from_iter+0x130/0xa60
[ 29.808295] Modules linked in:
[ 29.808742] CPU: 0 PID: 514 Comm: repro Not tainted 6.2.0-rc2-88603b6dc419 #2
[ 29.809931] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.14.0-0-g155821a1990b-prebuilt.qemu.org 04/01/2014
[ 29.811422] RIP: 0010:_copy_from_iter+0x130/0xa60
[ 29.812072] Code: 41 5e 41 5f 5d c3 cc cc cc cc e8 5b 16 58 ff be 79 02 00 00 48 c7 c7 3c 55 94 83 e8 5a 18 7a ff e9 3f ff ff ff e8 40 16 58 ff <0f> 0b 31 db 5
[ 29.814474] RSP: 0018:ffffc90000fdf988 EFLAGS: 00010246
[ 29.815182] RAX: 0000000000000000 RBX: 0000000000001000 RCX: ffffffff81d40343
[ 29.816120] RDX: 0000000000000000 RSI: ffff88800dfe4680 RDI: 0000000000000002
[ 29.817224] RBP: ffffc90000fdfa18 R08: ffffc90000fdfa3f R09: 000000000000ffff
[ 29.818177] R10: ffffea000049bc00 R11: 0000000000000000 R12: ffffc90000fdfad0
[ 29.819119] R13: 0000000000000000 R14: ffffea000049b000 R15: 0000000000000000
[ 29.820057] FS: 00007f9207ab6740(0000) GS:ffff88807dc00000(0000) knlGS:0000000000000000
[ 29.821161] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 29.821945] CR2: 0000000020000041 CR3: 000000000dd8a005 CR4: 0000000000770ef0
[ 29.822890] PKRU: 55555554
[ 29.823270] Call Trace:
[ 29.823615] <TASK>
[ 29.823924] ? __sanitizer_cov_trace_pc+0x25/0x60
[ 29.824597] ? bio_add_hw_page+0x234/0x2e0
[ 29.825228] ? write_comp_data+0x2f/0x90
[ 29.825782] copy_page_from_iter+0x1aa/0x370
[ 29.826377] ? write_comp_data+0x2f/0x90
[ 29.826928] blk_rq_map_user_iov+0x531/0xa70
[ 29.827550] blk_rq_map_user+0x86/0xc0
[ 29.828093] blk_rq_map_user_io+0xbe/0xd0
[ 29.828665] sg_common_write.isra.22+0x5fd/0xb10
[ 29.829390] sg_write+0x43a/0x750
[ 29.829894] ? __lock_acquire+0xa26/0x1d30
[ 29.830493] ? write_comp_data+0x2f/0x90
[ 29.831038] ? __sanitizer_cov_trace_pc+0x25/0x60
[ 29.831685] ? security_file_permission+0x177/0x340
[ 29.832365] ? __sanitizer_cov_trace_pc+0x25/0x60
[ 29.833348] ? write_comp_data+0x2f/0x90
[ 29.834039] vfs_write+0x1b6/0x780
[ 29.834533] ? __pfx_sg_write+0x10/0x10
[ 29.835074] ? __sanitizer_cov_trace_pc+0x25/0x60
[ 29.835716] ? write_comp_data+0x2f/0x90
[ 29.836256] ? write_comp_data+0x2f/0x90
[ 29.836816] ksys_write+0x9f/0x170
[ 29.837346] __x64_sys_write+0x27/0x30
[ 29.838001] do_syscall_64+0x3b/0x90
[ 29.838530] entry_SYSCALL_64_after_hwframe+0x72/0xdc
[ 29.839266] RIP: 0033:0x7f9207bdb59d
[ 29.839766] Code: 00 c3 66 2e 0f 1f 84 00 00 00 00 00 90 f3 0f 1e fa 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 8
[ 29.842219] RSP: 002b:00007ffe7ecdd768 EFLAGS: 00000213 ORIG_RAX: 0000000000000001
[ 29.843335] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f9207bdb59d
[ 29.844277] RDX: 0000000000000058 RSI: 0000000020000080 RDI: 0000000000000003
[ 29.845273] RBP: 00007ffe7ecdd780 R08: 002367732f766564 R09: 00007ffe7ecdd860
[ 29.846288] R10: 000000000000000f R11: 0000000000000213 R12: 00000000004010a0
[ 29.847228] R13: 00007ffe7ecdd860 R14: 0000000000000000 R15: 0000000000000000
[ 29.848182] </TASK>
[ 29.848516] irq event stamp: 4703
[ 29.848970] hardirqs last enabled at (4711): [<ffffffff811d48a1>] __up_console_sem+0x91/0xb0
[ 29.850278] hardirqs last disabled at (4720): [<ffffffff811d4886>] __up_console_sem+0x76/0xb0
[ 29.851409] softirqs last enabled at (4336): [<ffffffff82f9c213>] __do_softirq+0x323/0x48a
[ 29.852533] softirqs last disabled at (4213): [<ffffffff81123152>] irq_exit_rcu+0xd2/0x100
[ 29.853659] ---[ end trace 0000000000000000 ]---
"
Bisected and found that the bad commit is as below:
a41dad905e5a388f88435a517de102e9b2c8e43d
iov_iter: saner checks for attempt to copy to/from iterator

After revert above commit on top of v6.2-rc2 kernel, this issue was gone.

Reproduced code, bisect logs and kconfig info are in link:
https://github.com/xupengfe/syzkaller_logs/tree/main/221228_010310__copy_from_iter/230103_copy_from_iter_v6.2-rc2

I hope it's helpful.

Thanks!
BR.


On 2022-12-30 at 10:33:02 +0800, Pengfei Xu wrote:
> Hi Viro,
>
> Related email link:
> https://lore.kernel.org/lkml/Y5WlLoCBcHbfKBD5@ZenIV/
>
> syzbot link:
> https://syzkaller.appspot.com/bug?id=4694bd1c1c0019f067af5b6e14e8ef02431b6b34
>
>
> I reproduced on TGL-H with v6.2-rc1 kernel.
>
> All reproduced code bisect info are in link:
> https://github.com/xupengfe/syzkaller_logs/tree/main/221228_010310__copy_from_iter
>
> I hope it's helpful.
>
> Thanks!
> BR.

2023-01-05 04:44:10

by Al Viro

[permalink] [raw]
Subject: [Q] is the amount of residual bytes still not guaranteed for to be available for some old SCSI drivers? (was Re: Update bisect info and new repro code for "[syzbot] WARNING in _copy_from_iter")

On Thu, Jan 05, 2023 at 09:48:10AM +0800, Pengfei Xu wrote:
> Hi Viro,
>
> It's a soft remind: "_copy_from_iter" WARNING issue was still reproduced
> in v6.2-rc2 mainline kernel in guest.

sorry, had been sick ;-/

I see what's going on there; it's this bit:

if ((iov_iter_rw(iter) == WRITE &&
(!map_data || !map_data->null_mapped)) ||
(map_data && map_data->from_user)) {
ret = bio_copy_from_iter(bio, iter);
if (ret)
goto cleanup;

The "map_data && map_data->from_user" part is what I'd missed.
Mea culpa.

That code really is reading from destination here; in a lot of
respects that's broken (consider the case when destination is
mapped write-only), but it's a deliberate behaviour.

Origin is in commit ecb554a846f8 "block: fix sg SG_DXFER_TO_FROM_DEV
regression". Before trying to kludge around that, how much of the
original problem is still there?

Are there still low-level drivers that don't bother with scsi_set_resid()
for passthrough requests? IOW, do we need to play with
copy the entire destination into kernel buffer
handle REQ_OP_DRV_IN request, overwriting the copy
copy the entire buffer back to destination
all because we can't tell how much data had been copied in?
Because if we had the length of that sucker in sg_rq_end_io(),
we could just arrange for bio->bmd->iter truncated to actual
amount read and that would be it.

NOTE: no other users of blk_rq_map_user_io() go anywhere near that
weirdness; it's really just /dev/sg*.

If we that's approach is not feasible, we can always deal with
that in bio_copy_from_iter() - forcibly flip ->data_source for the
duration, which is OK for all kinds of iov_iter that can reach that
thing; it would work, but that's really ugly ;-/ If there's really
no way to get the amount of data actually transferred, that's what
we'll have to do, but it would be much saner to avoid the entire
song and dance and just copy the right amount out...