Bug 202755

Summary: read fault when mounting and operating a crafted btrfs image
Product: File System Reporter: Jungyeon (jungyeon)
Component: btrfsAssignee: BTRFS virtual assignee (fs_btrfs)
Status: RESOLVED CODE_FIX    
Severity: normal CC: dsterba, wqu
Priority: P1    
Hardware: All   
OS: Linux   
Kernel Version: 5.0-rc8 Subsystem:
Regression: No Bisected commit-id:
Attachments: The (compressed) crafted image which causes crash
04.c
Minimized test case

Description Jungyeon 2019-03-04 20:38:06 UTC
Created attachment 281483 [details]
The (compressed) crafted image which causes crash

- Overview
After mounting crafted image, I got kernel panic because of null pointer dereference while running attached program.

- Reproduce
mkdir test
mount -t btrfs 04.img test 
gcc 04.c
cp a.out test
cd test
./a.out

- Messages
[  125.531334] btrfs bad mapping eb start 29761536 len 4096, wanted 1787708 2410692
[  125.533687] BUG: unable to handle kernel NULL pointer dereference at 00000000000003e4
[  125.535624] #PF error: [normal kernel read fault]
[  125.536836] PGD 800000022b892067 P4D 800000022b892067 PUD 22b891067 PMD 0 
[  125.538509] Oops: 0000 [#1] SMP PTI
[  125.539376] CPU: 0 PID: 627 Comm: in:imklog Tainted: G        W         5.0.0-rc8+ #9
[  125.541291] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1ubuntu1 04/01/2014
[  125.543458] RIP: 0010:fsnotify+0x39a/0x3d0
[  125.544468] Code: c7 80 65 15 8a 89 45 a8 e8 23 3d e3 ff 8b 45 a8 e9 3e ff ff ff 31 c0 eb e2 48 8b 02 48 8b 58 08 4c 8d 60 e0 8b 80 f8 00 00 00 <0b> 83 e4 03 00 00 e9 d3 fc ff ff 45 31 ff e9 42 fd ff ff 31 c0 e9
[  125.549012] RSP: 0018:ffffa8360108fe10 EFLAGS: 00010246
[  125.550283] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000001
[  125.552004] RDX: ffff9066f3543610 RSI: 0000000000000001 RDI: 0000000000000000
[  125.553737] RBP: ffffa8360108fe98 R08: 0000000000000000 R09: 0000000000000000
[  125.555462] R10: ffffc90108bb1a80 R11: ffff9066f7401500 R12: ffff9066ebb4e000
[  125.557201] R13: 0000000000000001 R14: ffff9066f25102d0 R15: ffff9066f3543610
[  125.558929] FS:  00007f5ab210c700(0000) GS:ffff9066f7a00000(0000) knlGS:0000000000000000
[  125.562877] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  125.564292] CR2: 00000000000003e4 CR3: 000000022beee006 CR4: 00000000000206f0
[  125.566052] Call Trace:
[  125.566674]  vfs_read+0x127/0x140
[  125.567501]  ksys_read+0x55/0xc0
[  125.568305]  __x64_sys_read+0x1a/0x20
[  125.569231]  do_syscall_64+0x5a/0x110
[  125.570147]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[  125.571393] RIP: 0033:0x7f5ab455b51d
[  125.572286] Code: be 20 00 00 75 10 b8 00 00 00 00 0f 05 48 3d 01 f0 ff ff 73 31 c3 48 83 ec 08 e8 4e fc ff ff 48 89 04 24 b8 00 00 00 00 0f 05 <48> 8b 3c 24 48 89 c2 e8 97 fc ff ff 48 89 d0 48 83 c4 08 48 3d 01
[  125.576868] RSP: 002b:00007f5ab20eb580 EFLAGS: 00000293 ORIG_RAX: 0000000000000000
[  125.578711] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f5ab455b51d
[  125.580449] RDX: 0000000000001fa0 RSI: 00007f5ab20ebda0 RDI: 0000000000000004
[  125.582195] RBP: 0000000000ab32d0 R08: 0000000000000000 R09: 0000000000000000
[  125.583925] R10: 00007f5ab20eb3d0 R11: 0000000000000293 R12: 00007f5ab20ebda0
[  125.585713] R13: 0000000000001fa0 R14: 0000000000001f9f R15: 00007f5ab20ebe96
[  125.587451] Modules linked in:
[  125.588214] CR2: 00000000000003e4
[  125.589069] BUG: unable to handle kernel NULL pointer dereference at 0000000000000000
[  125.591006] #PF error: [INSTR]
[  125.591788] PGD 800000022b892067 P4D 800000022b892067 PUD 22b891067 PMD 0 
[  125.593498] Oops: 0010 [#2] SMP PTI
[  125.594373] CPU: 0 PID: 627 Comm: in:imklog Tainted: G      D W         5.0.0-rc8+ #9
[  125.596296] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1ubuntu1 04/01/2014
[  125.598536] RIP: 0010:          (null)
[  125.599476] Code: Bad RIP value.
[  125.600293] RSP: 0018:ffff9066f7a03d88 EFLAGS: 00010046
[  125.601602] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
[  125.603351] RDX: 0000000000000000 RSI: 0000000000000001 RDI: ffff9066ebb74a38
[  125.605114] RBP: ffff9066f7a03dd0 R08: 0000000000000000 R09: ffff9066f7a03de8
[  125.606862] R10: 0000000000000000 R11: 0000000000000000 R12: ffff9066f7a03de8
[  125.608611] R13: ffffffffffffffe8 R14: ffffffff89a7e018 R15: 0000000000000000
[  125.610407] FS:  00007f5ab210c700(0000) GS:ffff9066f7a00000(0000) knlGS:0000000000000000
[  125.612387] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  125.613815] CR2: ffffffffffffffd6 CR3: 000000022beee006 CR4: 00000000000206f0
[  125.615565] Call Trace:
[  125.616188]  <IRQ>
[  125.616712]  ? __wake_up_common+0x8c/0x130
[  125.617747]  __wake_up_common_lock+0x80/0xc0
[  125.618816]  __wake_up+0x13/0x20
[  125.619632]  wake_up_klogd_work_func+0x40/0x60
[  125.620758]  irq_work_run_list+0x55/0x80
[  125.621749]  ? tick_sched_do_timer+0x60/0x60
[  125.622810]  irq_work_tick+0x40/0x50
[  125.623706]  update_process_times+0x42/0x60
[  125.624785]  tick_sched_handle+0x29/0x60
[  125.625762]  tick_sched_timer+0x3c/0x80
[  125.626716]  __hrtimer_run_queues+0x106/0x270
[  125.627798]  hrtimer_interrupt+0x116/0x240
[  125.628828]  smp_apic_timer_interrupt+0x6f/0x150
[  125.629971]  apic_timer_interrupt+0xf/0x20
[  125.630987]  </IRQ>
[  125.631526] RIP: 0010:oops_end+0x78/0xf0
[  125.632503] Code: 7e 99 05 00 8b 05 00 34 d4 01 8d 50 ff 85 d2 89 15 f5 33 d4 01 75 0e 48 c7 c7 ac 64 f7 89 c6 07 00 66 66 66 90 48 89 df 57 9d <66> 66 90 66 90 e8 ee 9d 05 00 be 02 00 00 00 48 c7 c7 c0 64 f7 89
[  125.637084] RSP: 0018:ffffa8360108fb78 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff13
[  125.638935] RAX: 0000000000000001 RBX: 0000000000000246 RCX: 0000000000000006
[  125.640688] RDX: 0000000000000000 RSI: 0000000000000001 RDI: 0000000000000246
[  125.642442] RBP: ffffa8360108fb90 R08: 0000000000000001 R09: 0000000000000005
[  125.644176] R10: ffff9066eb2d9500 R11: ffffa8360108fa0d R12: 0000000000000009
[  125.645965] R13: ffffa8360108fd68 R14: ffff9066eb2d9500 R15: 000000000000000b
[  125.647712]  no_context+0x1e9/0x540
[  125.648584]  ? __switch_to_asm+0x40/0x70
[  125.649568]  ? __switch_to_asm+0x34/0x70
[  125.650537]  ? __switch_to_asm+0x40/0x70
[  125.651512]  ? vsnprintf+0x25b/0x4c0
[  125.652404]  __bad_area_nosemaphore+0x50/0x220
[  125.653513]  bad_area+0x46/0x50
[  125.654298]  __do_page_fault+0x386/0x4c0
[  125.655269]  do_page_fault+0x2e/0xf0
[  125.656162]  do_async_page_fault+0x1a/0x80
[  125.657197]  async_page_fault+0x1e/0x30
[  125.658156] RIP: 0010:fsnotify+0x39a/0x3d0
[  125.659176] Code: c7 80 65 15 8a 89 45 a8 e8 23 3d e3 ff 8b 45 a8 e9 3e ff ff ff 31 c0 eb e2 48 8b 02 48 8b 58 08 4c 8d 60 e0 8b 80 f8 00 00 00 <0b> 83 e4 03 00 00 e9 d3 fc ff ff 45 31 ff e9 42 fd ff ff 31 c0 e9
[  125.663731] RSP: 0018:ffffa8360108fe10 EFLAGS: 00010246
[  125.665039] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000001
[  125.666790] RDX: ffff9066f3543610 RSI: 0000000000000001 RDI: 0000000000000000
[  125.668545] RBP: ffffa8360108fe98 R08: 0000000000000000 R09: 0000000000000000
[  125.670335] R10: ffffc90108bb1a80 R11: ffff9066f7401500 R12: ffff9066ebb4e000
[  125.672066] R13: 0000000000000001 R14: ffff9066f25102d0 R15: ffff9066f3543610
[  125.673816]  vfs_read+0x127/0x140
[  125.674641]  ksys_read+0x55/0xc0
[  125.675442]  __x64_sys_read+0x1a/0x20
[  125.676348]  do_syscall_64+0x5a/0x110
[  125.677270]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[  125.678523] RIP: 0033:0x7f5ab455b51d
[  125.679417] Code: be 20 00 00 75 10 b8 00 00 00 00 0f 05 48 3d 01 f0 ff ff 73 31 c3 48 83 ec 08 e8 4e fc ff ff 48 89 04 24 b8 00 00 00 00 0f 05 <48> 8b 3c 24 48 89 c2 e8 97 fc ff ff 48 89 d0 48 83 c4 08 48 3d 01
[  125.683990] RSP: 002b:00007f5ab20eb580 EFLAGS: 00000293 ORIG_RAX: 0000000000000000
[  125.685873] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f5ab455b51d
[  125.687603] RDX: 0000000000001fa0 RSI: 00007f5ab20ebda0 RDI: 0000000000000004
[  125.689346] RBP: 0000000000ab32d0 R08: 0000000000000000 R09: 0000000000000000
[  125.691077] R10: 00007f5ab20eb3d0 R11: 0000000000000293 R12: 00007f5ab20ebda0
[  125.692848] R13: 0000000000001fa0 R14: 0000000000001f9f R15: 00007f5ab20ebe96
[  125.694581] Modules linked in:
[  125.695344] CR2: 0000000000000000
[  125.696170] ---[ end trace b52a1926ac5ee9d4 ]---
[  125.697320] RIP: 0010:fsnotify+0x39a/0x3d0
[  125.698327] Code: c7 80 65 15 8a 89 45 a8 e8 23 3d e3 ff 8b 45 a8 e9 3e ff ff ff 31 c0 eb e2 48 8b 02 48 8b 58 08 4c 8d 60 e0 8b 80 f8 00 00 00 <0b> 83 e4 03 00 00 e9 d3 fc ff ff 45 31 ff e9 42 fd ff ff 31 c0 e9
[  125.702852] RSP: 0018:ffffa8360108fe10 EFLAGS: 00010246
[  125.704130] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000001
[  125.705905] RDX: ffff9066f3543610 RSI: 0000000000000001 RDI: 0000000000000000
[  125.707640] RBP: ffffa8360108fe98 R08: 0000000000000000 R09: 0000000000000000
[  125.709409] R10: ffffc90108bb1a80 R11: ffff9066f7401500 R12: ffff9066ebb4e000
[  125.711137] R13: 0000000000000001 R14: ffff9066f25102d0 R15: ffff9066f3543610
[  125.712881] FS:  00007f5ab210c700(0000) GS:ffff9066f7a00000(0000) knlGS:0000000000000000
[  125.714838] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  125.716235] CR2: ffffffffffffffd6 CR3: 000000022beee006 CR4: 00000000000206f0
[  125.718019] Kernel panic - not syncing: Fatal exception in interrupt
[  125.732966] Kernel Offset: 0x7200000 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffffbfffffff)
[  125.735587] ---[ end Kernel panic - not syncing: Fatal exception in interrupt ]---
Comment 1 Jungyeon 2019-03-04 20:38:51 UTC
Created attachment 281485 [details]
04.c
Comment 2 Jungyeon 2019-03-07 03:52:18 UTC
Created attachment 281549 [details]
Minimized test case

Attaching minimized version of program with the same result. (Use this)
Comment 3 Qu Wenruo 2019-03-12 06:06:50 UTC
Thanks for the report (and all the other reports)

It indeed exposes a problem where first key verification is designed to solve, but some other part doesn't co-operate well.

With all your script and image, it's not that hard to reproduce.

Just a small tip for your later reports, please include previous btrfs error lines.

Especially lines like "BTRFS error (device loop0): tree first key mismatch detected, bytenr=29761536 parent_transid=19 key expected=(18446744073709551606,128,79691776) has=(18446744073709551606,128,8798638964736)" will help us to locate the bug in seconds, other than minutes.

Thanks,
Qu
Comment 4 Jungyeon 2019-03-12 09:17:42 UTC
I see. I will. Thanks.
Comment 5 David Sterba 2019-05-21 12:16:12 UTC
Thanks for the report. Fixed by

448de471cd4cab0ced "btrfs: Check the first key and level for cached extent buffer"

537f38f019fa0b76 "btrfs: Correctly free extent buffer in case btree_read_extent_buffer_pages fails"

, now in 5.2-rc.