* ceph_read_iter NULL pointer dereference
@ 2024-08-02 16:39 Luis Henriques
2024-08-05 5:11 ` Xiubo Li
0 siblings, 1 reply; 3+ messages in thread
From: Luis Henriques @ 2024-08-02 16:39 UTC (permalink / raw)
To: Xiubo Li; +Cc: ceph-devel
Hi Xiubo,
I was wondering if you ever seen the BUG below. I've debugged it a bit
and the issue seems occurs here, while doing the SetPageUptodate():
if (ret <= 0)
left = 0;
else if (off + ret > i_size)
left = i_size - off;
else
left = ret;
while (left > 0) {
size_t plen, copied;
plen = min_t(size_t, left, PAGE_SIZE - page_off);
SetPageUptodate(pages[idx]);
copied = copy_page_to_iter(pages[idx++],
page_off, plen, to);
off += copied;
left -= copied;
page_off = 0;
if (copied < plen) {
ret = -EFAULT;
break;
}
}
So, the issue is that we have idx > num_pages. And I'm almost sure that's
because of i_size being '0' and 'left' ending up with a huge value. But
haven't managed to figure out yet why i_size is '0'.
(Note: I'll be offline next week, but I'll continue looking into this the
week after. But I figured I should report the bug anyway, in case you've
seen something similar.)
Cheers,
--
Luís
BUG: kernel NULL pointer dereference, address: 0000000000000002
#PF: supervisor write access in kernel mode
#PF: error_code(0x0002) - not-present page
PGD 1032b4067 P4D 1032b4067 PUD 1032ce067 PMD 0
Oops: Oops: 0002 [#1] PREEMPT SMP
CPU: 0 UID: 0 PID: 427 Comm: python3 Not tainted 6.11.0-rc1+ #14
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.2-3-gd478f380-prebuilt.qemu.org 04/01/2014
RIP: 0010:__ceph_sync_read+0x4fd/0xa60
Code: 31 f6 4d 89 e7 4d 85 ff 0f 84 ed 03 00 00 ba 00 10 00 00 49 63 c6 48 29 f2 48 8d 04 c3 4c 39 fa 48 8b 08 49 0f 47 d7 49 89 d4 <f0> 80 09 08 48 8b 38 48 8b 4d b8 41 836
RSP: 0018:ffffc900008dfcb0 EFLAGS: 00010207
RAX: ffff888101858000 RBX: ffff888101856000 RCX: 0000000000000002
RDX: 0000000000001000 RSI: 0000000000000000 RDI: 00000000282c61c0
RBP: ffffc900008dfd80 R08: 0000000000000001 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000012c00 R12: 0000000000001000
R13: 0000000000421000 R14: 0000000000000400 R15: ffffffffffbdf000
FS: 00007f2eccd69040(0000) GS:ffff88813bc00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000000000000002 CR3: 0000000103e0e000 CR4: 00000000000006b0
Call Trace:
<TASK>
? __die+0x23/0x60
? page_fault_oops+0x158/0x450
? __ceph_sync_read+0x4fd/0xa60
? search_module_extables+0x4e/0x70
? exc_page_fault+0x2ab/0x880
? asm_exc_page_fault+0x26/0x30
? __ceph_sync_read+0x4fd/0xa60
ceph_read_iter+0x3eb/0x8f0
? rcu_core+0x997/0xa60
? lock_release+0x148/0x2b0
? vfs_read+0x244/0x310
vfs_read+0x244/0x310
ksys_read+0x6d/0xf0
do_syscall_64+0x71/0x140
entry_SYSCALL_64_after_hwframe+0x4b/0x53
RIP: 0033:0x7f2ecce6209d
Code: 31 c0 e9 c6 fe ff ff 50 48 8d 3d 66 55 0a 00 e8 89 fe 01 00 66 0f 1f 84 00 00 00 00 00 80 3d 41 25 0e 00 00 74 17 31 c0 0f 05 <48> 3d 00 f0 ff ff 77 5b c3 66 2e 0f 1fc
RSP: 002b:00007ffcdaa10578 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
RAX: ffffffffffffffda RBX: 0000000000a840d8 RCX: 00007f2ecce6209d
RDX: 0000000000400000 RSI: 0000000027ec61c0 RDI: 0000000000000004
RBP: 00007f2eccd68fc0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000001 R11: 0000000000000246 R12: 0000000000400000
R13: 0000000027ec61c0 R14: 0000000000000004 R15: 0000000000000000
</TASK>
Modules linked in:
CR2: 0000000000000002
---[ end trace 0000000000000000 ]---
RIP: 0010:__ceph_sync_read+0x4fd/0xa60
Code: 31 f6 4d 89 e7 4d 85 ff 0f 84 ed 03 00 00 ba 00 10 00 00 49 63 c6 48 29 f2 48 8d 04 c3 4c 39 fa 48 8b 08 49 0f 47 d7 49 89 d4 <f0> 80 09 08 48 8b 38 48 8b 4d b8 41 836
RSP: 0018:ffffc900008dfcb0 EFLAGS: 00010207
RAX: ffff888101858000 RBX: ffff888101856000 RCX: 0000000000000002
RDX: 0000000000001000 RSI: 0000000000000000 RDI: 00000000282c61c0
RBP: ffffc900008dfd80 R08: 0000000000000001 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000012c00 R12: 0000000000001000
R13: 0000000000421000 R14: 0000000000000400 R15: ffffffffffbdf000
FS: 00007f2eccd69040(0000) GS:ffff88813bc00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007fac71216a40 CR3: 0000000103e0e000 CR4: 00000000000006b0
^ permalink raw reply [flat|nested] 3+ messages in thread
* Re: ceph_read_iter NULL pointer dereference
2024-08-02 16:39 ceph_read_iter NULL pointer dereference Luis Henriques
@ 2024-08-05 5:11 ` Xiubo Li
2024-08-12 9:35 ` Luis Henriques
0 siblings, 1 reply; 3+ messages in thread
From: Xiubo Li @ 2024-08-05 5:11 UTC (permalink / raw)
To: Luis Henriques; +Cc: ceph-devel
Hi Luis,
Thanks for your reporting, BTW, could this be reproduceable ?
This is also the first time I see this crash BUG.
The 'i_size == 0' could be easy to reproduce, please see my following
debug logs:
++++++++++++++++++++++++++++
ceph_read_iter: 0~1024 trying to get caps on 000000006a438277
100000001f7.fffffffffffffffe
try_get_cap_refs: 000000006a438277 100000001f7.fffffffffffffffe need
Fr want Fc
__ceph_caps_issued: 000000006a438277 100000001f7.fffffffffffffffe cap
000000001a8b6d16 issued pAsLsXsFrw
try_get_cap_refs: 000000006a438277 100000001f7.fffffffffffffffe have
pAsLsXsFrw but not Fc (revoking -)
try_get_cap_refs: 000000006a438277 100000001f7.fffffffffffffffe ret 1
got Fr
ceph_read_iter: sync 000000006a438277 100000001f7.fffffffffffffffe
0~1024 got cap refs on Fr
ceph_sync_read: on file 00000000e029b65e 0~400
__ceph_sync_read: on inode 000000006a438277
100000001f7.fffffffffffffffe 0~400
__ceph_sync_read: orig 0~1024 reading 0~1024
__ceph_sync_read: 0~1024 got -2 i_size 0
__ceph_sync_read: result 0 retry_op 0
ceph_read_iter: 000000006a438277 100000001f7.fffffffffffffffe dropping
cap refs on Fr = 0
__ceph_put_cap_refs: 000000006a438277 100000001f7.fffffffffffffffe had
Fr last
__ceph_caps_issued: 000000006a438277 100000001f7.fffffffffffffffe cap
000000001a8b6d16 issued pAsLsXsFrw
+++++++++++++++++++++++++++++++++
I just created one empty file and then in Client.A open it for r/w, and
then open the same file in Client.B and did a simple read.
Currently ceph kclient won't check the 'i_size' before sending out the
sync read request to Rados, but will do it after it getting the contents
back, As I remembered this logic comply to the "MIX" filelock state in MDS:
[LOCK_MIX] = { 0, false, LOCK_MIX, 0, 0, REQ, ANY,
0, 0, 0, CEPH_CAP_GRD|CEPH_CAP_GWR|CEPH_CAP_GLAZYIO,0,0,CEPH_CAP_GRD },
You can raise one ceph tracker for this.
Thanks
- Xiubo
On 8/3/24 00:39, Luis Henriques wrote:
> Hi Xiubo,
>
> I was wondering if you ever seen the BUG below. I've debugged it a bit
> and the issue seems occurs here, while doing the SetPageUptodate():
>
> if (ret <= 0)
> left = 0;
> else if (off + ret > i_size)
> left = i_size - off;
> else
> left = ret;
> while (left > 0) {
> size_t plen, copied;
>
> plen = min_t(size_t, left, PAGE_SIZE - page_off);
> SetPageUptodate(pages[idx]);
> copied = copy_page_to_iter(pages[idx++],
> page_off, plen, to);
> off += copied;
> left -= copied;
> page_off = 0;
> if (copied < plen) {
> ret = -EFAULT;
> break;
> }
> }
>
> So, the issue is that we have idx > num_pages. And I'm almost sure that's
> because of i_size being '0' and 'left' ending up with a huge value. But
> haven't managed to figure out yet why i_size is '0'.
>
> (Note: I'll be offline next week, but I'll continue looking into this the
> week after. But I figured I should report the bug anyway, in case you've
> seen something similar.)
>
> Cheers,
^ permalink raw reply [flat|nested] 3+ messages in thread
* Re: ceph_read_iter NULL pointer dereference
2024-08-05 5:11 ` Xiubo Li
@ 2024-08-12 9:35 ` Luis Henriques
0 siblings, 0 replies; 3+ messages in thread
From: Luis Henriques @ 2024-08-12 9:35 UTC (permalink / raw)
To: Xiubo Li; +Cc: ceph-devel
On Mon, Aug 05 2024, Xiubo Li wrote:
> Hi Luis,
>
> Thanks for your reporting, BTW, could this be reproduceable ?
>
> This is also the first time I see this crash BUG.
>
>
> The 'i_size == 0' could be easy to reproduce, please see my following debug
> logs:
>
> ++++++++++++++++++++++++++++
>
> ceph_read_iter: 0~1024 trying to get caps on 000000006a438277
> 100000001f7.fffffffffffffffe
> try_get_cap_refs: 000000006a438277 100000001f7.fffffffffffffffe need Fr want Fc
> __ceph_caps_issued: 000000006a438277 100000001f7.fffffffffffffffe cap
> 000000001a8b6d16 issued pAsLsXsFrw
> try_get_cap_refs: 000000006a438277 100000001f7.fffffffffffffffe have pAsLsXsFrw
> but not Fc (revoking -)
> try_get_cap_refs: 000000006a438277 100000001f7.fffffffffffffffe ret 1 got Fr
> ceph_read_iter: sync 000000006a438277 100000001f7.fffffffffffffffe 0~1024 got
> cap refs on Fr
> ceph_sync_read: on file 00000000e029b65e 0~400
> __ceph_sync_read: on inode 000000006a438277 100000001f7.fffffffffffffffe 0~400
> __ceph_sync_read: orig 0~1024 reading 0~1024
> __ceph_sync_read: 0~1024 got -2 i_size 0
> __ceph_sync_read: result 0 retry_op 0
> ceph_read_iter: 000000006a438277 100000001f7.fffffffffffffffe dropping cap refs
> on Fr = 0
> __ceph_put_cap_refs: 000000006a438277 100000001f7.fffffffffffffffe had Fr last
> __ceph_caps_issued: 000000006a438277 100000001f7.fffffffffffffffe cap
> 000000001a8b6d16 issued pAsLsXsFrw
> +++++++++++++++++++++++++++++++++
>
> I just created one empty file and then in Client.A open it for r/w, and then
> open the same file in Client.B and did a simple read.
>
> Currently ceph kclient won't check the 'i_size' before sending out the sync read
> request to Rados, but will do it after it getting the contents back, As I
> remembered this logic comply to the "MIX" filelock state in MDS:
>
> [LOCK_MIX] = { 0, false, LOCK_MIX, 0, 0, REQ, ANY, 0, 0,
> 0, CEPH_CAP_GRD|CEPH_CAP_GWR|CEPH_CAP_GLAZYIO,0,0,CEPH_CAP_GRD },
>
> You can raise one ceph tracker for this.
I'll do that, and thanks for analysis. I'll need to catch-up with a few
things first after being a week offline, but I'll get back to this bug
shortly.
Cheers,
--
Luís
>
> Thanks
>
> - Xiubo
>
> On 8/3/24 00:39, Luis Henriques wrote:
>> Hi Xiubo,
>>
>> I was wondering if you ever seen the BUG below. I've debugged it a bit
>> and the issue seems occurs here, while doing the SetPageUptodate():
>>
>> if (ret <= 0)
>> left = 0;
>> else if (off + ret > i_size)
>> left = i_size - off;
>> else
>> left = ret;
>> while (left > 0) {
>> size_t plen, copied;
>>
>> plen = min_t(size_t, left, PAGE_SIZE - page_off);
>> SetPageUptodate(pages[idx]);
>> copied = copy_page_to_iter(pages[idx++],
>> page_off, plen, to);
>> off += copied;
>> left -= copied;
>> page_off = 0;
>> if (copied < plen) {
>> ret = -EFAULT;
>> break;
>> }
>> }
>>
>> So, the issue is that we have idx > num_pages. And I'm almost sure that's
>> because of i_size being '0' and 'left' ending up with a huge value. But
>> haven't managed to figure out yet why i_size is '0'.
>>
>> (Note: I'll be offline next week, but I'll continue looking into this the
>> week after. But I figured I should report the bug anyway, in case you've
>> seen something similar.)
>>
>> Cheers,
>
^ permalink raw reply [flat|nested] 3+ messages in thread
end of thread, other threads:[~2024-08-12 9:35 UTC | newest]
Thread overview: 3+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2024-08-02 16:39 ceph_read_iter NULL pointer dereference Luis Henriques
2024-08-05 5:11 ` Xiubo Li
2024-08-12 9:35 ` Luis Henriques
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.