* Re: [syzbot] [kernel?] KASAN: stack-out-of-bounds Read in __show_regs (2)
[not found] <000000000000a8c856061ae85e20@google.com>
@ 2024-06-25 1:22 ` Tetsuo Handa
2024-07-01 12:43 ` Tetsuo Handa
2024-08-01 23:39 ` syzbot
1 sibling, 1 reply; 8+ messages in thread
From: Tetsuo Handa @ 2024-06-25 1:22 UTC (permalink / raw)
To: syzbot, bp, dave.hansen, hpa, linux-kernel, mingo,
syzkaller-bugs, tglx, x86, kasan-dev, linux-mm
Hello.
This report is triggered by my debug printk() patch at
https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git/commit/net/core/rtnetlink.c?id=5210cbe9a47fc5c1f43ba16d481e6335f3e2f345
but I can't find where the bug is (x86 bug or mm bug or kasan bug or my bug).
On 2024/06/15 16:06, syzbot wrote:
> Hello,
>
> syzbot found the following issue on:
>
> HEAD commit: a957267fa7e9 Add linux-next specific files for 20240611
> git tree: linux-next
> console output: https://syzkaller.appspot.com/x/log.txt?x=171e6e56980000
> kernel config: https://syzkaller.appspot.com/x/.config?x=9a880e96898e79f8
> dashboard link: https://syzkaller.appspot.com/bug?extid=e9be5674af5e3a0b9ecc
> compiler: Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40
Quoting from https://syzkaller.appspot.com/text?tag=CrashReport&x=17786fb1980000
and https://syzkaller.appspot.com/text?tag=CrashLog&x=15e0202a980000 :
----------------------------------------
BUG: KASAN: stack-out-of-bounds in __show_regs+0xa6/0x610 arch/x86/kernel/process_64.c:83
Read of size 8 at addr ffffc90008807618 by task syz.0.1430/9588
CPU: 0 UID: 0 PID: 9588 Comm: syz.0.1430 Not tainted 6.10.0-rc5-next-20240624-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/07/2024
Call Trace:
<IRQ>
__dump_stack lib/dump_stack.c:94 [inline]
dump_stack_lvl+0x241/0x360 lib/dump_stack.c:120
print_address_description mm/kasan/report.c:377 [inline]
print_report+0x169/0x550 mm/kasan/report.c:488
kasan_report+0x143/0x180 mm/kasan/report.c:601
__show_regs+0xa6/0x610 arch/x86/kernel/process_64.c:83
show_trace_log_lvl+0x3d4/0x520 arch/x86/kernel/dumpstack.c:301
sched_show_task+0x578/0x740 kernel/sched/core.c:7506
report_rtnl_holders+0x1ba/0x2d0 net/core/rtnetlink.c:104
call_timer_fn+0x18e/0x650 kernel/time/timer.c:1792
expire_timers kernel/time/timer.c:1843 [inline]
__run_timers kernel/time/timer.c:2417 [inline]
__run_timer_base+0x66a/0x8e0 kernel/time/timer.c:2428
run_timer_base kernel/time/timer.c:2437 [inline]
run_timer_softirq+0xb7/0x170 kernel/time/timer.c:2447
handle_softirqs+0x2c4/0x970 kernel/softirq.c:554
__do_softirq kernel/softirq.c:588 [inline]
invoke_softirq kernel/softirq.c:428 [inline]
__irq_exit_rcu+0xf4/0x1c0 kernel/softirq.c:637
irq_exit_rcu+0x9/0x30 kernel/softirq.c:649
instr_sysvec_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1043 [inline]
sysvec_apic_timer_interrupt+0xa6/0xc0 arch/x86/kernel/apic/apic.c:1043
</IRQ>
<TASK>
asm_sysvec_apic_timer_interrupt+0x1a/0x20 arch/x86/include/asm/idtentry.h:702
RIP: 0010:__raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:152 [inline]
RIP: 0010:_raw_spin_unlock_irqrestore+0xd8/0x140 kernel/locking/spinlock.c:194
Code: 9c 8f 44 24 20 42 80 3c 23 00 74 08 4c 89 f7 e8 0e 94 61 f6 f6 44 24 21 02 75 52 41 f7 c7 00 02 00 00 74 01 fb bf 01 00 00 00 <e8> c3 10 ca f5 65 8b 05 b4 54 6b 74 85 c0 74 43 48 c7 04 24 0e 36
RSP: 0018:ffffc9000407f600 EFLAGS: 00000206
RAX: 13958dc9d919f000 RBX: 1ffff9200080fec4 RCX: ffffffff816fd2da
RDX: dffffc0000000000 RSI: ffffffff8bcac820 RDI: 0000000000000001
RBP: ffffc9000407f690 R08: ffffffff92fe47ef R09: 1ffffffff25fc8fd
R10: dffffc0000000000 R11: fffffbfff25fc8fe R12: dffffc0000000000
R13: 1ffff9200080fec0 R14: ffffc9000407f620 R15: 0000000000000246
spin_unlock_irqrestore include/linux/spinlock.h:406 [inline]
__wake_up_common_lock+0x18c/0x1e0 kernel/sched/wait.c:108
__unix_dgram_recvmsg+0x5f4/0x12f0 net/unix/af_unix.c:2415
sock_recvmsg_nosec+0x18e/0x1d0 net/socket.c:1046
____sys_recvmsg+0x3c0/0x470 net/socket.c:2814
___sys_recvmsg net/socket.c:2858 [inline]
do_recvmmsg+0x474/0xae0 net/socket.c:2952
__sys_recvmmsg net/socket.c:3031 [inline]
__do_sys_recvmmsg net/socket.c:3054 [inline]
__se_sys_recvmmsg net/socket.c:3047 [inline]
__x64_sys_recvmmsg+0x199/0x250 net/socket.c:3047
do_syscall_x64 arch/x86/entry/common.c:52 [inline]
do_syscall_64+0xf3/0x230 arch/x86/entry/common.c:83
entry_SYSCALL_64_after_hwframe+0x77/0x7f
RIP: 0033:0x7fdfbaf75d39
Code: ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 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 ff ff 73 01 c3 48 c7 c1 a8 ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007fdfbbc7e048 EFLAGS: 00000246 ORIG_RAX: 000000000000012b
RAX: ffffffffffffffda RBX: 00007fdfbb104070 RCX: 00007fdfbaf75d39
RDX: 0000000000010106 RSI: 00000000200000c0 RDI: 0000000000000003
RBP: 00007fdfbaff6766 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000002 R11: 0000000000000246 R12: 0000000000000000
R13: 000000000000006e R14: 00007fdfbb104070 R15: 00007ffeafeb36a8
</TASK>
The buggy address belongs to the virtual mapping at
[ffffc90008800000, ffffc90008809000) created by:
copy_process+0x5d1/0x3d90 kernel/fork.c:2206
The buggy address belongs to the physical page:
page: refcount:1 mapcount:0 mapping:0000000000000000 index:0x0 pfn:0x295f2
flags: 0xfff00000000000(node=0|zone=1|lastcpupid=0x7ff)
raw: 00fff00000000000 0000000000000000 dead000000000122 0000000000000000
raw: 0000000000000000 0000000000000000 00000001ffffffff 0000000000000000
page dumped because: kasan: bad access detected
page_owner tracks the page as allocated
page last allocated via order 0, migratetype Unmovable, gfp_mask 0x2dc2(GFP_KERNEL|__GFP_HIGHMEM|__GFP_NOWARN|__GFP_ZERO), pid 1052, tgid 1052 (kworker/u8:5), ts 20453244600, free_ts 0
set_page_owner include/linux/page_owner.h:32 [inline]
post_alloc_hook+0x1f3/0x230 mm/page_alloc.c:1500
prep_new_page mm/page_alloc.c:1508 [inline]
get_page_from_freelist+0x2ccb/0x2d80 mm/page_alloc.c:3487
__alloc_pages_noprof+0x256/0x6c0 mm/page_alloc.c:4745
alloc_pages_mpol_noprof+0x3e8/0x680 mm/mempolicy.c:2263
vm_area_alloc_pages mm/vmalloc.c:3576 [inline]
__vmalloc_area_node mm/vmalloc.c:3652 [inline]
__vmalloc_node_range_noprof+0x971/0x1460 mm/vmalloc.c:3833
alloc_thread_stack_node kernel/fork.c:313 [inline]
dup_task_struct+0x444/0x8c0 kernel/fork.c:1114
copy_process+0x5d1/0x3d90 kernel/fork.c:2206
kernel_clone+0x226/0x8f0 kernel/fork.c:2788
user_mode_thread+0x132/0x1a0 kernel/fork.c:2866
call_usermodehelper_exec_work+0x5c/0x230 kernel/umh.c:172
process_one_work kernel/workqueue.c:3224 [inline]
process_scheduled_works+0xa2c/0x1830 kernel/workqueue.c:3305
worker_thread+0x86d/0xd40 kernel/workqueue.c:3383
kthread+0x2f0/0x390 kernel/kthread.c:389
ret_from_fork+0x4b/0x80 arch/x86/kernel/process.c:144
ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:244
page_owner free stack trace missing
Memory state around the buggy address:
ffffc90008807500: 00 00 00 00 00 f3 f3 f3 f3 f3 f3 f3 00 00 00 00
ffffc90008807580: 00 00 00 00 00 00 00 00 f1 f1 f1 f1 00 f2 f2 f2
>ffffc90008807600: 00 f3 f3 f3 00 00 00 00 00 00 00 00 00 00 00 00
^
ffffc90008807680: 00 00 00 00 f1 f1 f1 f1 00 f2 f2 f2 00 f3 f3 f3
ffffc90008807700: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
==================================================================
----------------------------------------
----------------------------------------
[ 560.831831][ C0] DEBUG: holding rtnl_mutex for 937 jiffies.
[ 560.838015][ C0] task:kworker/u8:9 state:R running task stack:20216 pid:2460 tgid:2460 ppid:2 flags:0x00004000
[ 560.849882][ C0] Workqueue: netns cleanup_net
[ 560.854770][ C0] Call Trace:
[ 560.854789][ C0] <TASK>
[ 560.872376][ C0] __schedule+0x17e8/0x4a20
[ 560.877336][ C0] ? mark_lock+0x9a/0x360
[ 560.881823][ C0] ? lockdep_hardirqs_on_prepare+0x43d/0x780
[ 560.887887][ C0] ? __virt_addr_valid+0x183/0x520
[ 560.893171][ C0] ? __pfx_lockdep_hardirqs_on_prepare+0x10/0x10
[ 560.899593][ C0] ? lock_release+0xbf/0x9f0
[ 560.904330][ C0] ? __pfx___schedule+0x10/0x10
[ 560.909271][ C0] ? lockdep_hardirqs_on+0x99/0x150
[ 560.914617][ C0] ? mark_lock+0x9a/0x360
[ 560.919119][ C0] preempt_schedule_irq+0xfb/0x1c0
[ 560.924392][ C0] ? __pfx_preempt_schedule_irq+0x10/0x10
[ 560.931783][ C0] irqentry_exit+0x5e/0x90
[ 560.936590][ C0] asm_sysvec_reschedule_ipi+0x1a/0x20
[ 560.942783][ C0] RIP: 0010:synchronize_rcu+0x0/0x360
[ 560.948403][ C0] Code: e1 07 80 c1 03 38 c1 0f 8c 97 fe ff ff 4c 89 f7 e8 15 50 80 00 e9 8a fe ff ff 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 <f3> 0f 1e fa 55 48 89 e5 41 57 41 56 41 55 41 54 53 48 83 e4 e0 48
[ 560.968242][ C0] RSP: 76c0:0000000000000a06 EFLAGS: 1ffff92001100ed4
[ 560.975129][ C0] ==================================================================
[ 560.994479][ C0] BUG: KASAN: stack-out-of-bounds in __show_regs+0xa6/0x610
[ 561.002642][ C0] Read of size 8 at addr ffffc90008807618 by task syz.0.1430/9588
[ 561.014598][ C0]
[ 561.017321][ C0] CPU: 0 UID: 0 PID: 9588 Comm: syz.0.1430 Not tainted 6.10.0-rc5-next-20240624-syzkaller #0
[ 561.028952][ C0] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/07/2024
[ 561.043847][ C0] Call Trace:
[ 561.047213][ C0] <IRQ>
[ 561.050101][ C0] dump_stack_lvl+0x241/0x360
[ 561.054963][ C0] ? __pfx_dump_stack_lvl+0x10/0x10
[ 561.073046][ C0] ? __pfx__printk+0x10/0x10
[ 561.077786][ C0] ? _printk+0xd5/0x120
[ 561.082123][ C0] print_report+0x169/0x550
[ 561.086775][ C0] ? __virt_addr_valid+0xbd/0x520
[ 561.091947][ C0] ? __show_regs+0xa6/0x610
[ 561.096544][ C0] kasan_report+0x143/0x180
[ 561.101170][ C0] ? show_opcodes+0x148/0x170
[ 561.105909][ C0] ? __show_regs+0xa6/0x610
[ 561.110457][ C0] __show_regs+0xa6/0x610
[ 561.114858][ C0] ? asm_sysvec_reschedule_ipi+0x1a/0x20
[ 561.120539][ C0] ? asm_sysvec_reschedule_ipi+0x1a/0x20
[ 561.126227][ C0] show_trace_log_lvl+0x3d4/0x520
[ 561.131292][ C0] ? __pfx_synchronize_rcu+0x10/0x10
[ 561.136630][ C0] sched_show_task+0x578/0x740
[ 561.141466][ C0] ? report_rtnl_holders+0x183/0x2d0
[ 561.147055][ C0] ? __pfx__printk+0x10/0x10
[ 561.151699][ C0] ? __pfx_sched_show_task+0x10/0x10
[ 561.157153][ C0] report_rtnl_holders+0x1ba/0x2d0
[ 561.162519][ C0] ? report_rtnl_holders+0x20/0x2d0
[ 561.167755][ C0] call_timer_fn+0x18e/0x650
[ 561.172361][ C0] ? call_timer_fn+0xc0/0x650
[ 561.177086][ C0] ? __pfx_report_rtnl_holders+0x10/0x10
[ 561.182785][ C0] ? __pfx_call_timer_fn+0x10/0x10
[ 561.187939][ C0] ? __pfx_report_rtnl_holders+0x10/0x10
[ 561.193631][ C0] ? __pfx_report_rtnl_holders+0x10/0x10
[ 561.199303][ C0] ? __pfx_report_rtnl_holders+0x10/0x10
[ 561.204994][ C0] ? _raw_spin_unlock_irq+0x23/0x50
[ 561.210231][ C0] ? lockdep_hardirqs_on+0x99/0x150
[ 561.215469][ C0] ? __pfx_report_rtnl_holders+0x10/0x10
[ 561.221120][ C0] __run_timer_base+0x66a/0x8e0
[ 561.226093][ C0] ? __pfx___run_timer_base+0x10/0x10
[ 561.231493][ C0] ? __pfx_lockdep_hardirqs_on_prepare+0x10/0x10
[ 561.237874][ C0] run_timer_softirq+0xb7/0x170
[ 561.242832][ C0] handle_softirqs+0x2c4/0x970
[ 561.247626][ C0] ? __irq_exit_rcu+0xf4/0x1c0
[ 561.252429][ C0] ? __pfx_handle_softirqs+0x10/0x10
[ 561.257856][ C0] ? irqtime_account_irq+0xd4/0x1e0
[ 561.263090][ C0] __irq_exit_rcu+0xf4/0x1c0
[ 561.267711][ C0] ? __pfx___irq_exit_rcu+0x10/0x10
[ 561.272931][ C0] irq_exit_rcu+0x9/0x30
[ 561.277231][ C0] sysvec_apic_timer_interrupt+0xa6/0xc0
[ 561.283185][ C0] </IRQ>
[ 561.286769][ C0] <TASK>
[ 561.289972][ C0] asm_sysvec_apic_timer_interrupt+0x1a/0x20
[ 561.297172][ C0] RIP: 0010:_raw_spin_unlock_irqrestore+0xd8/0x140
[ 561.307112][ C0] Code: 9c 8f 44 24 20 42 80 3c 23 00 74 08 4c 89 f7 e8 0e 94 61 f6 f6 44 24 21 02 75 52 41 f7 c7 00 02 00 00 74 01 fb bf 01 00 00 00 <e8> c3 10 ca f5 65 8b 05 b4 54 6b 74 85 c0 74 43 48 c7 04 24 0e 36
[ 561.327228][ C0] RSP: 0018:ffffc9000407f600 EFLAGS: 00000206
[ 561.333355][ C0] RAX: 13958dc9d919f000 RBX: 1ffff9200080fec4 RCX: ffffffff816fd2da
[ 561.341352][ C0] RDX: dffffc0000000000 RSI: ffffffff8bcac820 RDI: 0000000000000001
[ 561.349458][ C0] RBP: ffffc9000407f690 R08: ffffffff92fe47ef R09: 1ffffffff25fc8fd
[ 561.357460][ C0] R10: dffffc0000000000 R11: fffffbfff25fc8fe R12: dffffc0000000000
[ 561.365478][ C0] R13: 1ffff9200080fec0 R14: ffffc9000407f620 R15: 0000000000000246
[ 561.373533][ C0] ? mark_lock+0x9a/0x360
[ 561.378221][ C0] ? __pfx__raw_spin_unlock_irqrestore+0x10/0x10
[ 561.385142][ C0] ? autoremove_wake_function+0x37/0x110
[ 561.391145][ C0] __wake_up_common_lock+0x18c/0x1e0
[ 561.396936][ C0] __unix_dgram_recvmsg+0x5f4/0x12f0
[ 561.403018][ C0] ? __pfx___unix_dgram_recvmsg+0x10/0x10
[ 561.409788][ C0] ? __pfx___might_resched+0x10/0x10
[ 561.415745][ C0] ? iovec_from_user+0x61/0x240
[ 561.421927][ C0] ? unix_dgram_recvmsg+0xb6/0xe0
[ 561.427965][ C0] ? __pfx_unix_dgram_recvmsg+0x10/0x10
[ 561.435584][ C0] sock_recvmsg_nosec+0x18e/0x1d0
[ 561.441322][ C0] ____sys_recvmsg+0x3c0/0x470
[ 561.446583][ C0] ? __pfx_____sys_recvmsg+0x10/0x10
[ 561.455788][ C0] ? __might_fault+0xaa/0x120
[ 561.460634][ C0] do_recvmmsg+0x474/0xae0
[ 561.465088][ C0] ? __pfx___futex_wait+0x10/0x10
[ 561.470148][ C0] ? __pfx_do_recvmmsg+0x10/0x10
[ 561.475130][ C0] ? __pfx_futex_wake_mark+0x10/0x10
[ 561.480509][ C0] ? futex_wait+0x285/0x360
[ 561.485124][ C0] ? __pfx_futex_wait+0x10/0x10
[ 561.490014][ C0] ? fd_install+0x9c/0x5d0
[ 561.494459][ C0] ? __pfx_lock_release+0x10/0x10
[ 561.499504][ C0] ? __pfx_do_futex+0x10/0x10
[ 561.504229][ C0] __x64_sys_recvmmsg+0x199/0x250
[ 561.510481][ C0] ? __pfx___x64_sys_recvmmsg+0x10/0x10
[ 561.517399][ C0] ? do_syscall_64+0x100/0x230
[ 561.522660][ C0] ? do_syscall_64+0xb6/0x230
[ 561.529823][ C0] do_syscall_64+0xf3/0x230
[ 561.534742][ C0] ? clear_bhb_loop+0x35/0x90
[ 561.540096][ C0] entry_SYSCALL_64_after_hwframe+0x77/0x7f
[ 561.546133][ C0] RIP: 0033:0x7fdfbaf75d39
[ 561.550744][ C0] Code: ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 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 ff ff 73 01 c3 48 c7 c1 a8 ff ff ff f7 d8 64 89 01 48
[ 561.571064][ C0] RSP: 002b:00007fdfbbc7e048 EFLAGS: 00000246 ORIG_RAX: 000000000000012b
[ 561.580376][ C0] RAX: ffffffffffffffda RBX: 00007fdfbb104070 RCX: 00007fdfbaf75d39
[ 561.588397][ C0] RDX: 0000000000010106 RSI: 00000000200000c0 RDI: 0000000000000003
[ 561.596400][ C0] RBP: 00007fdfbaff6766 R08: 0000000000000000 R09: 0000000000000000
[ 561.604404][ C0] R10: 0000000000000002 R11: 0000000000000246 R12: 0000000000000000
[ 561.612415][ C0] R13: 000000000000006e R14: 00007fdfbb104070 R15: 00007ffeafeb36a8
[ 561.620458][ C0] </TASK>
[ 561.623517][ C0]
[ 561.625876][ C0] The buggy address belongs to the virtual mapping at
[ 561.625876][ C0] [ffffc90008800000, ffffc90008809000) created by:
[ 561.625876][ C0] copy_process+0x5d1/0x3d90
[ 561.643549][ C0]
[ 561.645879][ C0] The buggy address belongs to the physical page:
[ 561.652306][ C0] page: refcount:1 mapcount:0 mapping:0000000000000000 index:0x0 pfn:0x295f2
[ 561.661135][ C0] flags: 0xfff00000000000(node=0|zone=1|lastcpupid=0x7ff)
[ 561.668346][ C0] raw: 00fff00000000000 0000000000000000 dead000000000122 0000000000000000
[ 561.677050][ C0] raw: 0000000000000000 0000000000000000 00000001ffffffff 0000000000000000
[ 561.685659][ C0] page dumped because: kasan: bad access detected
[ 561.692219][ C0] page_owner tracks the page as allocated
[ 561.697979][ C0] page last allocated via order 0, migratetype Unmovable, gfp_mask 0x2dc2(GFP_KERNEL|__GFP_HIGHMEM|__GFP_NOWARN|__GFP_ZERO), pid 1052, tgid 1052 (kworker/u8:5), ts 20453244600, free_ts 0
[ 561.716523][ C0] post_alloc_hook+0x1f3/0x230
[ 561.721344][ C0] get_page_from_freelist+0x2ccb/0x2d80
[ 561.727009][ C0] __alloc_pages_noprof+0x256/0x6c0
[ 561.732233][ C0] alloc_pages_mpol_noprof+0x3e8/0x680
[ 561.737727][ C0] __vmalloc_node_range_noprof+0x971/0x1460
[ 561.743664][ C0] dup_task_struct+0x444/0x8c0
[ 561.748479][ C0] copy_process+0x5d1/0x3d90
[ 561.753128][ C0] kernel_clone+0x226/0x8f0
[ 561.757766][ C0] user_mode_thread+0x132/0x1a0
[ 561.762660][ C0] call_usermodehelper_exec_work+0x5c/0x230
[ 561.768674][ C0] process_scheduled_works+0xa2c/0x1830
[ 561.774240][ C0] worker_thread+0x86d/0xd40
[ 561.778849][ C0] kthread+0x2f0/0x390
[ 561.782979][ C0] ret_from_fork+0x4b/0x80
[ 561.787453][ C0] ret_from_fork_asm+0x1a/0x30
[ 561.792332][ C0] page_owner free stack trace missing
[ 561.797698][ C0]
[ 561.800029][ C0] Memory state around the buggy address:
[ 561.805664][ C0] ffffc90008807500: 00 00 00 00 00 f3 f3 f3 f3 f3 f3 f3 00 00 00 00
[ 561.813728][ C0] ffffc90008807580: 00 00 00 00 00 00 00 00 f1 f1 f1 f1 00 f2 f2 f2
[ 561.821814][ C0] >ffffc90008807600: 00 f3 f3 f3 00 00 00 00 00 00 00 00 00 00 00 00
[ 561.829912][ C0] ^
[ 561.834781][ C0] ffffc90008807680: 00 00 00 00 f1 f1 f1 f1 00 f2 f2 f2 00 f3 f3 f3
[ 561.842858][ C0] ffffc90008807700: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 561.851024][ C0] ==================================================================
[ 561.859206][ C0] Kernel panic - not syncing: KASAN: panic_on_warn set ...
[ 561.866452][ C0] CPU: 0 UID: 0 PID: 9588 Comm: syz.0.1430 Not tainted 6.10.0-rc5-next-20240624-syzkaller #0
----------------------------------------
arch/x86/kernel/process_64.c:83 is
printk("%sRAX: %016lx RBX: %016lx RCX: %016lx\n",
log_lvl, regs->ax, regs->bx, regs->cx);
(which looks nothing special), and kernel stack area [ffffc90008800000, ffffc90008809000) is
32768 bytes + 4096 bytes (which looks sane to me), and ffffc90008807618 is within the 32768
bytes (which looks sane to me).
Kernel config is https://syzkaller.appspot.com/text?tag=KernelConfig&x=6221d1071c39b052 .
Can somebody find what is wrong?
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [syzbot] [kernel?] KASAN: stack-out-of-bounds Read in __show_regs (2)
2024-06-25 1:22 ` [syzbot] [kernel?] KASAN: stack-out-of-bounds Read in __show_regs (2) Tetsuo Handa
@ 2024-07-01 12:43 ` Tetsuo Handa
2024-07-01 15:10 ` Andrey Konovalov
0 siblings, 1 reply; 8+ messages in thread
From: Tetsuo Handa @ 2024-07-01 12:43 UTC (permalink / raw)
To: syzbot, linux-kernel, syzkaller-bugs, kasan-dev, linux-mm
Cc: bp, dave.hansen, hpa, mingo, tglx, x86
Hello, KASAN people.
I suspect that KASAN's metadata for kernel stack memory got out of sync for
unknown reason, for the stack trace of PID=7558 was successfully printed for
two times before KASAN complains upon trying to print for the the third time.
Would you decode what is this KASAN message saying?
Quoting from https://syzkaller.appspot.com/text?tag=CrashLog&x=119fd081980000 :
[ 226.304791][ C0] DEBUG: holding rtnl_mutex for 555 jiffies.
[ 226.310883][ C0] task:syz.1.750 state:R running task stack:24672 pid:7558 tgid:7558 ppid:5945 flags:0x00004006
[ 226.322705][ C0] Call Trace:
[ 226.326074][ C0] <TASK>
[ 226.329029][ C0] __schedule+0x17e8/0x4a20
[ 226.333672][ C0] ? __pfx___schedule+0x10/0x10
[ 226.338599][ C0] ? __pfx_lock_release+0x10/0x10
[ 226.343744][ C0] ? _raw_spin_unlock_irqrestore+0xdd/0x140
[ 226.349775][ C0] ? schedule+0x90/0x320
[ 226.354042][ C0] schedule+0x14b/0x320
[ 226.358254][ C0] synchronize_rcu_expedited+0x684/0x830
[ 226.364012][ C0] ? __pfx_synchronize_rcu_expedited+0x10/0x10
[ 226.370239][ C0] ? __pfx_wait_rcu_exp_gp+0x10/0x10
[ 226.375579][ C0] ? __pfx___might_resched+0x10/0x10
[ 226.380877][ C0] ? lockdep_hardirqs_on_prepare+0x43d/0x780
[ 226.386897][ C0] ? __pfx_autoremove_wake_function+0x10/0x10
[ 226.392985][ C0] ? __pfx_lockdep_hardirqs_on_prepare+0x10/0x10
[ 226.399381][ C0] synchronize_rcu+0x11b/0x360
[ 226.404181][ C0] ? __pfx_synchronize_rcu+0x10/0x10
[ 226.409555][ C0] lockdep_unregister_key+0x556/0x610
[ 226.414991][ C0] ? __pfx_lockdep_unregister_key+0x10/0x10
[ 226.420908][ C0] ? lockdep_hardirqs_on+0x99/0x150
[ 226.426160][ C0] ? __qdisc_destroy+0x150/0x410
[ 226.431211][ C0] ? kfree+0x149/0x360
[ 226.435414][ C0] ? __pfx_pfifo_fast_destroy+0x10/0x10
[ 226.441013][ C0] __qdisc_destroy+0x165/0x410
[ 226.445888][ C0] dev_shutdown+0x9b/0x440
[ 226.450334][ C0] unregister_netdevice_many_notify+0x9c7/0x1d20
[ 226.456717][ C0] ? __lock_acquire+0x1359/0x2000
[ 226.461786][ C0] ? __pfx_unregister_netdevice_many_notify+0x10/0x10
[ 226.468602][ C0] ? __asan_memset+0x23/0x50
[ 226.473208][ C0] ? skb_queue_purge_reason+0x2de/0x500
[ 226.478815][ C0] ? __asan_memset+0x23/0x50
[ 226.483423][ C0] ? skb_queue_purge_reason+0x2de/0x500
[ 226.489025][ C0] ? do_raw_spin_unlock+0x13c/0x8b0
[ 226.494244][ C0] unregister_netdevice_queue+0x303/0x370
[ 226.500013][ C0] ? __pfx_unregister_netdevice_queue+0x10/0x10
[ 226.506317][ C0] __tun_detach+0x6b6/0x1600
[ 226.510942][ C0] tun_chr_close+0x108/0x1b0
[ 226.515574][ C0] ? __pfx_tun_chr_close+0x10/0x10
[ 226.520705][ C0] __fput+0x24a/0x8a0
[ 226.524742][ C0] task_work_run+0x24f/0x310
[ 226.529352][ C0] ? __pfx_task_work_run+0x10/0x10
[ 226.534482][ C0] ? syscall_exit_to_user_mode+0xa3/0x370
[ 226.540265][ C0] syscall_exit_to_user_mode+0x168/0x370
[ 226.545967][ C0] do_syscall_64+0x100/0x230
[ 226.550580][ C0] ? clear_bhb_loop+0x35/0x90
[ 226.555306][ C0] entry_SYSCALL_64_after_hwframe+0x77/0x7f
[ 226.561215][ C0] RIP: 0033:0x7f2470375b99
[ 226.565668][ C0] RSP: 002b:00007ffd71072888 EFLAGS: 00000246 ORIG_RAX: 00000000000001b4
[ 226.574109][ C0] RAX: 0000000000000000 RBX: 00007f2470505aa0 RCX: 00007f2470375b99
[ 226.582119][ C0] RDX: 0000000000000000 RSI: 000000000000001e RDI: 0000000000000003
[ 226.590129][ C0] RBP: 00007f2470505aa0 R08: 0000000000000008 R09: 0000000871072b9f
[ 226.598153][ C0] R10: 00000000005f3974 R11: 0000000000000246 R12: 000000000003603f
[ 226.606256][ C0] R13: 0000000000000032 R14: 00007f2470505aa0 R15: 00007f2470504078
[ 226.614265][ C0] </TASK>
[ 226.617357][ C0]
[ 226.617357][ C0] Showing all locks held in the system:
[ 226.625107][ C0] 3 locks held by kworker/u8:0/11:
[ 226.630259][ C0] 2 locks held by getty/4850:
[ 226.634966][ C0] #0: ffff88802a6860a0 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x25/0x70
[ 226.644790][ C0] #1: ffffc9000312b2f0 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0x6b5/0x1e10
[ 226.654971][ C0] 2 locks held by syz.4.185/5862:
[ 226.660012][ C0] 2 locks held by syz.3.241/6079:
[ 226.665073][ C0] 1 lock held by syz-executor/7179:
[ 226.670288][ C0] 2 locks held by syz.1.750/7558:
[ 226.675345][ C0] #0: ffffffff8f5feac8 (rtnl_mutex){+.+.}-{3:3}, at: tun_chr_close+0x3e/0x1b0
[ 226.684379][ C0] #1: ffffffff8e33abf8 (rcu_state.exp_mutex){+.+.}-{3:3}, at: synchronize_rcu_expedited+0x381/0x830
[ 226.695348][ C0] 2 locks held by syz.0.757/7594:
[ 226.700384][ C0] #0: ffffffff8f6682f0 (cb_lock){++++}-{3:3}, at: genl_rcv+0x19/0x40
[ 226.708731][ C0] #1: ffffffff8f5feac8 (rtnl_mutex){+.+.}-{3:3}, at: nl80211_pre_doit+0x5f/0x8b0
[ 226.718045][ C0] 1 lock held by syz.3.764/7609:
[ 226.723082][ C0] 2 locks held by syz.2.767/7615:
[ 226.728152][ C0] #0: ffffc90000007c00 (net/core/rtnetlink.c:83){+.-.}-{0:0}, at: call_timer_fn+0xc0/0x650
[ 226.738338][ C0] #1: ffffffff8e335820 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x55/0x2a0
[ 226.748268][ C0] 3 locks held by syz-executor/7617:
[ 226.753568][ C0]
[ 226.755932][ C0] =============================================
[ 226.755932][ C0]
[ 227.343278][ T5144] usb 3-1: new high-speed USB device number 9 using dummy_hcd
[ 227.536711][ T5144] usb 3-1: config 0 interface 0 altsetting 0 endpoint 0x81 has an invalid bInterval 0, changing to 7
[ 227.568067][ T5144] usb 3-1: config 0 interface 0 altsetting 0 endpoint 0x81 has invalid wMaxPacketSize 0
[ 227.598514][ T5144] usb 3-1: New USB device found, idVendor=05ac, idProduct=022a, bcdDevice= 0.00
[ 227.621562][ T5144] usb 3-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[ 227.651457][ T5144] usb 3-1: config 0 descriptor??
[ 227.814998][ C0] DEBUG: holding rtnl_mutex for 706 jiffies.
[ 227.821075][ C0] task:syz.1.750 state:D stack:24672 pid:7558 tgid:7558 ppid:5945 flags:0x00004006
[ 227.831413][ C0] Call Trace:
[ 227.834732][ C0] <TASK>
[ 227.837686][ C0] __schedule+0x17e8/0x4a20
[ 227.842246][ C0] ? __pfx___schedule+0x10/0x10
[ 227.847165][ C0] ? __pfx_lock_release+0x10/0x10
[ 227.852388][ C0] ? _raw_spin_unlock_irqrestore+0xdd/0x140
[ 227.858350][ C0] ? schedule+0x90/0x320
[ 227.862622][ C0] schedule+0x14b/0x320
[ 227.866849][ C0] synchronize_rcu_expedited+0x684/0x830
[ 227.872517][ C0] ? __pfx_synchronize_rcu_expedited+0x10/0x10
[ 227.878773][ C0] ? __pfx_wait_rcu_exp_gp+0x10/0x10
[ 227.884098][ C0] ? __pfx___might_resched+0x10/0x10
[ 227.889440][ C0] ? lockdep_hardirqs_on_prepare+0x43d/0x780
[ 227.895470][ C0] ? __pfx_autoremove_wake_function+0x10/0x10
[ 227.901561][ C0] ? __pfx_lockdep_hardirqs_on_prepare+0x10/0x10
[ 227.907960][ C0] synchronize_rcu+0x11b/0x360
[ 227.912758][ C0] ? __pfx_synchronize_rcu+0x10/0x10
[ 227.918117][ C0] lockdep_unregister_key+0x556/0x610
[ 227.923521][ C0] ? __pfx_lockdep_unregister_key+0x10/0x10
[ 227.929465][ C0] ? lockdep_hardirqs_on+0x99/0x150
[ 227.934718][ C0] ? __qdisc_destroy+0x150/0x410
[ 227.939964][ C0] ? kfree+0x149/0x360
[ 227.944062][ C0] ? __pfx_pfifo_fast_destroy+0x10/0x10
[ 227.949668][ C0] __qdisc_destroy+0x165/0x410
[ 227.954466][ C0] dev_shutdown+0x9b/0x440
[ 227.958940][ C0] unregister_netdevice_many_notify+0x9c7/0x1d20
[ 227.965321][ C0] ? __lock_acquire+0x1359/0x2000
[ 227.970390][ C0] ? __pfx_unregister_netdevice_many_notify+0x10/0x10
[ 227.977386][ C0] ? __asan_memset+0x23/0x50
[ 227.982011][ C0] ? skb_queue_purge_reason+0x2de/0x500
[ 227.987621][ C0] ? __asan_memset+0x23/0x50
[ 227.992237][ C0] ? skb_queue_purge_reason+0x2de/0x500
[ 227.997854][ C0] ? do_raw_spin_unlock+0x13c/0x8b0
[ 228.003082][ C0] unregister_netdevice_queue+0x303/0x370
[ 228.008865][ C0] ? __pfx_unregister_netdevice_queue+0x10/0x10
[ 228.015177][ C0] __tun_detach+0x6b6/0x1600
[ 228.019812][ C0] tun_chr_close+0x108/0x1b0
[ 228.024437][ C0] ? __pfx_tun_chr_close+0x10/0x10
[ 228.029623][ C0] __fput+0x24a/0x8a0
[ 228.033651][ C0] task_work_run+0x24f/0x310
[ 228.038319][ C0] ? __pfx_task_work_run+0x10/0x10
[ 228.043546][ C0] ? syscall_exit_to_user_mode+0xa3/0x370
[ 228.049341][ C0] syscall_exit_to_user_mode+0x168/0x370
[ 228.055042][ C0] do_syscall_64+0x100/0x230
[ 228.059667][ C0] ? clear_bhb_loop+0x35/0x90
[ 228.064374][ C0] entry_SYSCALL_64_after_hwframe+0x77/0x7f
[ 228.070336][ C0] RIP: 0033:0x7f2470375b99
[ 228.074815][ C0] RSP: 002b:00007ffd71072888 EFLAGS: 00000246 ORIG_RAX: 00000000000001b4
[ 228.083252][ C0] RAX: 0000000000000000 RBX: 00007f2470505aa0 RCX: 00007f2470375b99
[ 228.091289][ C0] RDX: 0000000000000000 RSI: 000000000000001e RDI: 0000000000000003
[ 228.091369][ T5144] appletouch 3-1:0.0: Geyser mode initialized.
[ 228.099291][ C0] RBP: 00007f2470505aa0 R08: 0000000000000008 R09: 0000000871072b9f
[ 228.099348][ C0] R10: 00000000005f3974 R11: 0000000000000246 R12: 000000000003603f
[ 228.099364][ C0] R13: 0000000000000032 R14: 00007f2470505aa0 R15: 00007f2470504078
[ 228.099396][ C0] </TASK>
[ 228.099408][ C0]
[ 228.099408][ C0] Showing all locks held in the system:
[ 228.099452][ C0] 5 locks held by kworker/u8:7/2895:
[ 228.136372][ T5144] input: appletouch as /devices/platform/dummy_hcd.2/usb3/3-1/3-1:0.0/input/input11
[ 228.140345][ C0] 2 locks held by getty/4850:
[ 228.140365][ C0] #0: ffff88802a6860a0 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x25/0x70
[ 228.140438][ C0] #1: ffffc9000312b2f0 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0x6b5/0x1e10
[ 228.140505][ C0] 6 locks held by kworker/1:5/5144:
[ 228.140523][ C0] 2 locks held by syz.4.185/5862:
[ 228.140539][ C0] 4 locks held by syz.3.241/6079:
[ 228.140557][ C0] 2 locks held by syz.1.750/7558:
[ 228.140571][ C0] #0: ffffffff8f5feac8 (rtnl_mutex){+.+.}-{3:3}, at: tun_chr_close+0x3e/0x1b0
[ 228.140639][ C0] #1: ffffffff8e33abf8 (rcu_state.exp_mutex){+.+.}-{3:3}, at: synchronize_rcu_expedited+0x381/0x830
[ 228.140716][ C0] 2 locks held by syz.0.757/7594:
[ 228.140730][ C0] #0: ffffffff8f6682f0 (cb_lock){++++}-{3:3}, at: genl_rcv+0x19/0x40
[ 228.140791][ C0] #1: ffffffff8f5feac8 (rtnl_mutex){+.+.}-{3:3}, at: nl80211_pre_doit+0x5f/0x8b0
[ 228.140857][ C0] 2 locks held by syz.3.775/7633:
[ 228.140871][ C0] #0: ffffc9000499fb40 (net/core/rtnetlink.c:83){+.-.}-{0:0}, at: call_timer_fn+0xc0/0x650
[ 228.140931][ C0] #1: ffffffff8e335820 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x55/0x2a0
[ 228.140997][ C0]
[ 228.141004][ C0] =============================================
[ 228.141004][ C0]
[ 229.184903][ C0] DEBUG: holding rtnl_mutex for 843 jiffies.
[ 229.190994][ C0] task:syz.1.750 state:R running task stack:24672 pid:7558 tgid:7558 ppid:5945 flags:0x00004006
[ 229.202817][ C0] Call Trace:
[ 229.206142][ C0] <TASK>
[ 229.209088][ C0] __schedule+0x17e8/0x4a20
[ 229.213626][ C0] ? mark_lock+0x9a/0x360
[ 229.218009][ C0] ? lockdep_hardirqs_on_prepare+0x43d/0x780
[ 229.224013][ C0] ? __pfx_lockdep_hardirqs_on_prepare+0x10/0x10
[ 229.230388][ C0] ? __pfx___schedule+0x10/0x10
[ 229.235286][ C0] ? lockdep_hardirqs_on+0x99/0x150
[ 229.240775][ C0] ? mark_lock+0x9a/0x360
[ 229.245156][ C0] preempt_schedule_irq+0xfb/0x1c0
[ 229.250289][ C0] ? __pfx_preempt_schedule_irq+0x10/0x10
[ 229.256053][ C0] ? __pfx_pfifo_fast_destroy+0x10/0x10
[ 229.261637][ C0] irqentry_exit+0x5e/0x90
[ 229.266098][ C0] asm_sysvec_reschedule_ipi+0x1a/0x20
[ 229.271585][ C0] RIP: 0010:lockdep_unregister_key+0x56d/0x610
[ 229.277796][ C0] Code: ff 92 48 c7 c6 d0 b7 6f 81 e8 7f 04 0a 00 e8 ea 18 0a 00 e9 e5 fb ff ff e8 c0 06 21 0a 41 f7 c7 00 02 00 00 74 d0 fb 45 84 f6 <75> cf eb e0 90 0f 0b 90 45 31 f6 e9 62 ff ff ff 90 0f 0b 90 e9 a1
[ 229.297447][ C0] RSP: 0018:ffffc90003c4f820 EFLAGS: 00000246
[ 229.303630][ C0] RAX: dffffc0000000000 RBX: 1ffff92000789f0c RCX: ffffffff947f3803
[ 229.311661][ C0] RDX: 0000000000000001 RSI: ffffffff8bcad5e0 RDI: 1ffff92000789f0c
[ 229.319713][ C0] ==================================================================
[ 229.327779][ C0] BUG: KASAN: stack-out-of-bounds in __show_regs+0x172/0x610
[ 229.335174][ C0] Read of size 8 at addr ffffc90003c4f798 by task kworker/u8:5/234
[ 229.343506][ C0]
[ 229.345910][ C0] CPU: 0 UID: 0 PID: 234 Comm: kworker/u8:5 Not tainted 6.10.0-rc6-next-20240701-syzkaller #0
[ 229.356229][ C0] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/07/2024
[ 229.366301][ C0] Workqueue: bat_events batadv_nc_worker
[ 229.371979][ C0] Call Trace:
[ 229.375266][ C0] <IRQ>
[ 229.378119][ C0] dump_stack_lvl+0x241/0x360
[ 229.382825][ C0] ? __pfx_dump_stack_lvl+0x10/0x10
[ 229.388052][ C0] ? __pfx__printk+0x10/0x10
[ 229.392661][ C0] ? _printk+0xd5/0x120
[ 229.396840][ C0] print_report+0x169/0x550
[ 229.401361][ C0] ? __virt_addr_valid+0xbd/0x530
[ 229.406407][ C0] ? __show_regs+0x172/0x610
[ 229.411022][ C0] kasan_report+0x143/0x180
[ 229.415549][ C0] ? show_opcodes+0x148/0x170
[ 229.420251][ C0] ? __show_regs+0x172/0x610
[ 229.424865][ C0] __show_regs+0x172/0x610
[ 229.429297][ C0] ? asm_sysvec_reschedule_ipi+0x1a/0x20
[ 229.434949][ C0] ? wq_watchdog_touch+0xef/0x180
[ 229.439991][ C0] ? asm_sysvec_reschedule_ipi+0x1a/0x20
[ 229.445645][ C0] show_trace_log_lvl+0x3d4/0x520
[ 229.450700][ C0] ? lockdep_unregister_key+0x56d/0x610
[ 229.456267][ C0] sched_show_task+0x506/0x6d0
[ 229.461051][ C0] ? report_rtnl_holders+0x29e/0x3f0
[ 229.466361][ C0] ? __pfx__printk+0x10/0x10
[ 229.470970][ C0] ? __pfx_sched_show_task+0x10/0x10
[ 229.476270][ C0] ? _raw_spin_unlock_irqrestore+0xdd/0x140
[ 229.482180][ C0] ? __pfx__raw_spin_unlock_irqrestore+0x10/0x10
[ 229.488536][ C0] report_rtnl_holders+0x320/0x3f0
[ 229.493671][ C0] call_timer_fn+0x18e/0x650
[ 229.498279][ C0] ? call_timer_fn+0xc0/0x650
[ 229.502974][ C0] ? __pfx_report_rtnl_holders+0x10/0x10
[ 229.508624][ C0] ? __pfx_call_timer_fn+0x10/0x10
[ 229.513749][ C0] ? __pfx_report_rtnl_holders+0x10/0x10
[ 229.519403][ C0] ? __pfx_report_rtnl_holders+0x10/0x10
[ 229.525056][ C0] ? __pfx_report_rtnl_holders+0x10/0x10
[ 229.530709][ C0] ? _raw_spin_unlock_irq+0x23/0x50
[ 229.535920][ C0] ? lockdep_hardirqs_on+0x99/0x150
[ 229.541145][ C0] ? __pfx_report_rtnl_holders+0x10/0x10
[ 229.546796][ C0] __run_timer_base+0x66a/0x8e0
[ 229.551946][ C0] ? __pfx___run_timer_base+0x10/0x10
[ 229.557433][ C0] run_timer_softirq+0xb7/0x170
[ 229.562312][ C0] handle_softirqs+0x2c4/0x970
[ 229.567095][ C0] ? __irq_exit_rcu+0xf4/0x1c0
[ 229.571877][ C0] ? __pfx_handle_softirqs+0x10/0x10
[ 229.577184][ C0] ? irqtime_account_irq+0xd4/0x1e0
[ 229.582405][ C0] __irq_exit_rcu+0xf4/0x1c0
[ 229.587017][ C0] ? __pfx___irq_exit_rcu+0x10/0x10
[ 229.592330][ C0] irq_exit_rcu+0x9/0x30
[ 229.596591][ C0] sysvec_apic_timer_interrupt+0xa6/0xc0
[ 229.602250][ C0] </IRQ>
[ 229.605190][ C0] <TASK>
[ 229.608128][ C0] asm_sysvec_apic_timer_interrupt+0x1a/0x20
[ 229.614125][ C0] RIP: 0010:rcu_is_watching+0x3a/0xb0
[ 229.619525][ C0] Code: e8 4b 3b 17 0a 89 c3 83 f8 08 73 7a 49 bf 00 00 00 00 00 fc ff df 4c 8d 34 dd 40 6a de 8d 4c 89 f0 48 c1 e8 03 42 80 3c 38 00 <74> 08 4c 89 f7 e8 8c ac 80 00 48 c7 c3 98 7c 03 00 49 03 1e 48 89
[ 229.639321][ C0] RSP: 0018:ffffc90002fe7a00 EFLAGS: 00000246
[ 229.645414][ C0] RAX: 1ffffffff1bbcd48 RBX: 0000000000000000 RCX: ffffffff816f8930
[ 229.653403][ C0] RDX: 0000000000000000 RSI: ffffffff8c207ae0 RDI: ffffffff8c207aa0
[ 229.661389][ C0] RBP: ffffc90002fe7b48 R08: ffffffff8faf796f R09: 1ffffffff1f5ef2d
[ 229.669374][ C0] R10: dffffc0000000000 R11: fffffbfff1f5ef2e R12: 1ffff920005fcf50
[ 229.677448][ C0] R13: ffffffff8b5b3d7b R14: ffffffff8dde6a40 R15: dffffc0000000000
[ 229.685523][ C0] ? batadv_nc_worker+0xcb/0x610
[ 229.690482][ C0] ? lock_release+0xb0/0x9f0
[ 229.695095][ C0] lock_release+0xbf/0x9f0
[ 229.699531][ C0] ? __pfx_lock_acquire+0x10/0x10
[ 229.704573][ C0] ? batadv_nc_worker+0xcb/0x610
[ 229.709525][ C0] ? __pfx_lock_release+0x10/0x10
[ 229.714577][ C0] ? batadv_nc_worker+0xcb/0x610
[ 229.719556][ C0] batadv_nc_worker+0x28b/0x610
[ 229.724427][ C0] ? batadv_nc_worker+0xcb/0x610
[ 229.729383][ C0] ? process_scheduled_works+0x945/0x1830
[ 229.735214][ C0] process_scheduled_works+0xa2c/0x1830
[ 229.741055][ C0] ? __pfx_process_scheduled_works+0x10/0x10
[ 229.747056][ C0] ? assign_work+0x364/0x3d0
[ 229.751662][ C0] worker_thread+0x86d/0xd40
[ 229.756278][ C0] ? _raw_spin_unlock_irqrestore+0xdd/0x140
[ 229.762193][ C0] ? __kthread_parkme+0x169/0x1d0
[ 229.767245][ C0] ? __pfx_worker_thread+0x10/0x10
[ 229.772373][ C0] kthread+0x2f0/0x390
[ 229.776460][ C0] ? __pfx_worker_thread+0x10/0x10
[ 229.781595][ C0] ? __pfx_kthread+0x10/0x10
[ 229.786210][ C0] ret_from_fork+0x4b/0x80
[ 229.790645][ C0] ? __pfx_kthread+0x10/0x10
[ 229.795257][ C0] ret_from_fork_asm+0x1a/0x30
[ 229.800050][ C0] </TASK>
[ 229.803075][ C0]
[ 229.805402][ C0] The buggy address belongs to the virtual mapping at
[ 229.805402][ C0] [ffffc90003c48000, ffffc90003c51000) created by:
[ 229.805402][ C0] copy_process+0x5d1/0x3d70
[ 229.823040][ C0]
[ 229.825368][ C0] The buggy address belongs to the physical page:
[ 229.831782][ C0] page: refcount:1 mapcount:0 mapping:0000000000000000 index:0x8 pfn:0x60439
[ 229.840815][ C0] memcg:ffff88801ae90502
[ 229.845059][ C0] flags: 0xfff00000000000(node=0|zone=1|lastcpupid=0x7ff)
[ 229.852190][ C0] raw: 00fff00000000000 0000000000000000 dead000000000122 0000000000000000
[ 229.860795][ C0] raw: 0000000000000008 0000000000000000 00000001ffffffff ffff88801ae90502
[ 229.869388][ C0] page dumped because: kasan: bad access detected
[ 229.875810][ C0] page_owner tracks the page as allocated
[ 229.881541][ C0] page last allocated via order 0, migratetype Unmovable, gfp_mask 0x102dc2(GFP_HIGHUSER|__GFP_NOWARN|__GFP_ZERO), pid 5945, tgid 5945 (syz-executor), ts 214193789047, free_ts 213702691290
[ 229.900048][ C0] post_alloc_hook+0x1f3/0x230
[ 229.904836][ C0] get_page_from_freelist+0x2ccb/0x2d80
[ 229.910401][ C0] __alloc_pages_noprof+0x256/0x6c0
[ 229.915617][ C0] alloc_pages_mpol_noprof+0x3e8/0x680
[ 229.921098][ C0] __vmalloc_node_range_noprof+0x971/0x1460
[ 229.927002][ C0] dup_task_struct+0x444/0x8c0
[ 229.931782][ C0] copy_process+0x5d1/0x3d70
[ 229.936391][ C0] kernel_clone+0x226/0x8f0
[ 229.940907][ C0] __x64_sys_clone+0x258/0x2a0
[ 229.945685][ C0] do_syscall_64+0xf3/0x230
[ 229.950289][ C0] entry_SYSCALL_64_after_hwframe+0x77/0x7f
[ 229.956189][ C0] page last free pid 6079 tgid 6077 stack trace:
[ 229.962513][ C0] free_unref_page+0xd22/0xea0
[ 229.967289][ C0] __put_partials+0xeb/0x130
[ 229.971890][ C0] put_cpu_partial+0x17c/0x250
[ 229.976665][ C0] __slab_free+0x2ea/0x3d0
[ 229.981093][ C0] qlist_free_all+0x9e/0x140
[ 229.985702][ C0] kasan_quarantine_reduce+0x14f/0x170
[ 229.991174][ C0] __kasan_slab_alloc+0x23/0x80
[ 229.996036][ C0] kmem_cache_alloc_noprof+0x135/0x2a0
[ 230.001536][ C0] alloc_buffer_head+0x2a/0x290
[ 230.006397][ C0] folio_alloc_buffers+0x241/0x5b0
[ 230.011522][ C0] create_empty_buffers+0x3a/0x740
[ 230.016644][ C0] block_read_full_folio+0x25c/0xcd0
[ 230.021940][ C0] filemap_read_folio+0x1a0/0x790
[ 230.026979][ C0] do_read_cache_folio+0x134/0x820
[ 230.032104][ C0] do_read_cache_page+0x30/0x200
[ 230.037057][ C0] sysv_find_entry+0x1af/0x410
[ 230.041836][ C0]
[ 230.044183][ C0] Memory state around the buggy address:
[ 230.049816][ C0] ffffc90003c4f680: f2 f2 f2 f2 00 00 00 00 00 f3 f3 f3 f3 f3 f3 f3
[ 230.057889][ C0] ffffc90003c4f700: 00 00 00 00 00 00 00 00 00 00 00 00 f1 f1 f1 f1
[ 230.065961][ C0] >ffffc90003c4f780: 00 f2 f2 f2 00 f3 f3 f3 00 00 00 00 00 00 00 00
[ 230.074059][ C0] ^
[ 230.078915][ C0] ffffc90003c4f800: 00 00 00 00 00 00 00 00 f1 f1 f1 f1 00 f2 f2 f2
[ 230.086983][ C0] ffffc90003c4f880: 00 f3 f3 f3 00 00 00 00 00 00 00 00 00 00 00 00
[ 230.095056][ C0] ==================================================================
[ 230.103224][ C0] Kernel panic - not syncing: KASAN: panic_on_warn set ...
On 2024/06/25 10:22, Tetsuo Handa wrote:
> Hello.
>
> This report is triggered by my debug printk() patch at
> https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git/commit/net/core/rtnetlink.c?id=5210cbe9a47fc5c1f43ba16d481e6335f3e2f345
> but I can't find where the bug is (x86 bug or mm bug or kasan bug or my bug).
>
> On 2024/06/15 16:06, syzbot wrote:
>> Hello,
>>
>> syzbot found the following issue on:
>>
>> HEAD commit: a957267fa7e9 Add linux-next specific files for 20240611
>> git tree: linux-next
>> console output: https://syzkaller.appspot.com/x/log.txt?x=171e6e56980000
>> kernel config: https://syzkaller.appspot.com/x/.config?x=9a880e96898e79f8
>> dashboard link: https://syzkaller.appspot.com/bug?extid=e9be5674af5e3a0b9ecc
>> compiler: Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [syzbot] [kernel?] KASAN: stack-out-of-bounds Read in __show_regs (2)
2024-07-01 12:43 ` Tetsuo Handa
@ 2024-07-01 15:10 ` Andrey Konovalov
2024-07-02 6:11 ` Tetsuo Handa
0 siblings, 1 reply; 8+ messages in thread
From: Andrey Konovalov @ 2024-07-01 15:10 UTC (permalink / raw)
To: Tetsuo Handa
Cc: syzbot, linux-kernel, syzkaller-bugs, kasan-dev, linux-mm, bp,
dave.hansen, hpa, mingo, tglx, x86
On Mon, Jul 1, 2024 at 2:43 PM Tetsuo Handa
<penguin-kernel@i-love.sakura.ne.jp> wrote:
>
> Hello, KASAN people.
>
> I suspect that KASAN's metadata for kernel stack memory got out of sync for
> unknown reason, for the stack trace of PID=7558 was successfully printed for
> two times before KASAN complains upon trying to print for the the third time.
> Would you decode what is this KASAN message saying?
>
> Quoting from https://syzkaller.appspot.com/text?tag=CrashLog&x=119fd081980000 :
[...]
> [ 229.319713][ C0] ==================================================================
> [ 229.327779][ C0] BUG: KASAN: stack-out-of-bounds in __show_regs+0x172/0x610
> [ 229.335174][ C0] Read of size 8 at addr ffffc90003c4f798 by task kworker/u8:5/234
[...]
> [ 230.044183][ C0] Memory state around the buggy address:
> [ 230.049816][ C0] ffffc90003c4f680: f2 f2 f2 f2 00 00 00 00 00 f3 f3 f3 f3 f3 f3 f3
> [ 230.057889][ C0] ffffc90003c4f700: 00 00 00 00 00 00 00 00 00 00 00 00 f1 f1 f1 f1
> [ 230.065961][ C0] >ffffc90003c4f780: 00 f2 f2 f2 00 f3 f3 f3 00 00 00 00 00 00 00 00
> [ 230.074059][ C0] ^
> [ 230.078915][ C0] ffffc90003c4f800: 00 00 00 00 00 00 00 00 f1 f1 f1 f1 00 f2 f2 f2
> [ 230.086983][ C0] ffffc90003c4f880: 00 f3 f3 f3 00 00 00 00 00 00 00 00 00 00 00 00
> [ 230.095056][ C0] ==================================================================
I checked some of the other syzbot reports for this bug, and this
memory state part in some of them looks different.
Specifically, for
https://syzkaller.appspot.com/text?tag=CrashLog&x=14293f0e980000:
[ 1558.929174][ C1] Memory state around the buggy address:
[ 1558.934796][ C1] ffffc9000b8bf400: 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00
[ 1558.942852][ C1] ffffc9000b8bf480: 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00
[ 1558.950897][ C1] >ffffc9000b8bf500: 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00
[ 1558.958943][ C1] ^
[ 1558.964569][ C1] ffffc9000b8bf580: 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00
[ 1558.972613][ C1] ffffc9000b8bf600: 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00
This is weird, because if the metadata is 00, then the memory should
be accessible and there should be no KASAN report.
Which makes me believe you have some kind of a race in your patch (or
there's a race in the kernel that your patch somehow exposes). At
least between the moment KASAN detected the issue and the moment the
reporting procedure got to printing the memory state, the memory state
changed. As this is stack memory that comes from a vmalloc allocation,
I suspect the task whose stack had been at that location died, and
something else got mapped there.
This is my best guess, I hope it's helpful.
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [syzbot] [kernel?] KASAN: stack-out-of-bounds Read in __show_regs (2)
2024-07-01 15:10 ` Andrey Konovalov
@ 2024-07-02 6:11 ` Tetsuo Handa
2024-07-02 7:05 ` Tetsuo Handa
[not found] ` <CA+fCnZfxCWZYX-7vJzMcwN4vKguuskk5rGYA2Ntotw=owOZ6Sg@mail.gmail.com>
0 siblings, 2 replies; 8+ messages in thread
From: Tetsuo Handa @ 2024-07-02 6:11 UTC (permalink / raw)
To: Andrey Konovalov
Cc: syzbot, linux-kernel, syzkaller-bugs, kasan-dev, linux-mm, bp,
dave.hansen, hpa, mingo, tglx, x86
On 2024/07/02 0:10, Andrey Konovalov wrote:
> This is weird, because if the metadata is 00, then the memory should
> be accessible and there should be no KASAN report.
>
> Which makes me believe you have some kind of a race in your patch (or
> there's a race in the kernel that your patch somehow exposes).
Yes, I consider that my patch is exposing an existing race, for I can't
find a race in my patch. (Since
https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git/commit/?id=b96342141183ffa62bfed5998f9b808c84042322
calls get_task_struct() when recording in-use state, report_rtnl_holders()
can't trigger use-after-free even if the thread died. Also, since previous version
https://git.kernel.org/pub/scm/linux/kernel/git/next/linux-next.git/commit/?id=5210cbe9a47fc5c1f43ba16d481e6335f3e2f345
synchronously calls synchronize_rcu() when clearing in-use state,
report_rtnl_holders() can't trigger use-after-free because the thread
can't die before calling put_rtnl_holder(). The variable "now" cannot be
0, and !cmpxchg(&rtnl_started[idx], 0, now) must serve as a serialization
lock when recording in-use state.)
> At
> least between the moment KASAN detected the issue and the moment the
> reporting procedure got to printing the memory state, the memory state
> changed.
Indeed, the exact line KASAN complained at varies suggests that the
memory state is modified by somebody else.
> As this is stack memory that comes from a vmalloc allocation,
> I suspect the task whose stack had been at that location died, and
> something else got mapped there.
I consider that the task can't die while calling __show_regs() from
report_rtnl_holders().
>
> This is my best guess, I hope it's helpful.
Well, KASAN says "out-of-bounds". But the reported address
BUG: KASAN: stack-out-of-bounds in __show_regs+0x172/0x610
Read of size 8 at addr ffffc90003c4f798 by task kworker/u8:5/234
is within the kernel stack memory mapping
The buggy address belongs to the virtual mapping at
[ffffc90003c48000, ffffc90003c51000) created by:
copy_process+0x5d1/0x3d7
. Why is this "out-of-bounds" ? What boundary did KASAN compare with?
Is this just a race of KASAN detecting a problem and KASAN reporting
that problem? (But as I explained above, it is unlikely that the thread
to be reported can die while processing report_rtnl_holders()...)
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [syzbot] [kernel?] KASAN: stack-out-of-bounds Read in __show_regs (2)
2024-07-02 6:11 ` Tetsuo Handa
@ 2024-07-02 7:05 ` Tetsuo Handa
[not found] ` <CA+fCnZfxCWZYX-7vJzMcwN4vKguuskk5rGYA2Ntotw=owOZ6Sg@mail.gmail.com>
1 sibling, 0 replies; 8+ messages in thread
From: Tetsuo Handa @ 2024-07-02 7:05 UTC (permalink / raw)
To: Andrey Konovalov
Cc: syzbot, linux-kernel, syzkaller-bugs, kasan-dev, linux-mm, bp,
dave.hansen, hpa, mingo, tglx, x86
On 2024/07/02 15:11, Tetsuo Handa wrote:
> Well, KASAN says "out-of-bounds". But the reported address
>
> BUG: KASAN: stack-out-of-bounds in __show_regs+0x172/0x610
> Read of size 8 at addr ffffc90003c4f798 by task kworker/u8:5/234
>
> is within the kernel stack memory mapping
>
> The buggy address belongs to the virtual mapping at
> [ffffc90003c48000, ffffc90003c51000) created by:
> copy_process+0x5d1/0x3d7
>
> . Why is this "out-of-bounds" ? What boundary did KASAN compare with?
I think I found a hint. The KASAN message is printed when the call trace
starts with
__schedule()
preempt_schedule_irq()
irqentry_exit()
. That is, when preemption happens, KASAN by error tries to compare with
unintended stack boundary?
[ 504.507489][ C0] DEBUG: holding rtnl_mutex for 3212 jiffies.
[ 504.513708][ C0] task:kworker/u8:5 state:R running task stack:19992 pid:340 tgid:340 ppid:2 flags:0x00004000
[ 504.525827][ C0] Workqueue: netns cleanup_net
[ 504.530890][ C0] Call Trace:
[ 504.534213][ C0] <TASK>
[ 504.537244][ C0] __schedule+0x17e8/0x4a20
[ 504.541874][ C0] ? mark_lock+0x9a/0x360
[ 504.546279][ C0] ? lockdep_hardirqs_on_prepare+0x43d/0x780
[ 504.552396][ C0] ? __virt_addr_valid+0x183/0x520
[ 504.557711][ C0] ? __pfx_lockdep_hardirqs_on_prepare+0x10/0x10
[ 504.564121][ C0] ? lock_release+0xbf/0x9f0
[ 504.568918][ C0] ? __pfx___schedule+0x10/0x10
[ 504.573835][ C0] ? lockdep_hardirqs_on+0x99/0x150
[ 504.579189][ C0] ? mark_lock+0x9a/0x360
[ 504.583592][ C0] preempt_schedule_irq+0xfb/0x1c0
[ 504.588984][ C0] ? __pfx_preempt_schedule_irq+0x10/0x10
[ 504.594785][ C0] irqentry_exit+0x5e/0x90
[ 504.599421][ C0] asm_sysvec_reschedule_ipi+0x1a/0x20
[ 463.514954][ C1] DEBUG: holding rtnl_mutex for 993 jiffies.
[ 463.528845][ C1] task:kworker/u8:10 state:R running task stack:19856 pid:5725 tgid:5725 ppid:2 flags:0x00004000
[ 463.536743][ T9938] rock: corrupted directory entry. extent=41, offset=65536, size=8
[ 463.540652][ C1] Workqueue: netns cleanup_net
[ 463.553421][ C1] Call Trace:
[ 463.556740][ C1] <TASK>
[ 463.559706][ C1] __schedule+0x17e8/0x4a20
[ 463.564304][ C1] ? __pfx_validate_chain+0x10/0x10
[ 463.569611][ C1] ? __pfx___schedule+0x10/0x10
[ 463.574628][ C1] ? lockdep_hardirqs_on_prepare+0x43d/0x780
[ 463.580760][ C1] ? preempt_schedule_irq+0xf0/0x1c0
[ 463.586149][ C1] preempt_schedule_irq+0xfb/0x1c0
[ 463.591401][ C1] ? __pfx_preempt_schedule_irq+0x10/0x10
[ 463.597269][ C1] irqentry_exit+0x5e/0x90
[ 463.601834][ C1] asm_sysvec_apic_timer_interrupt+0x1a/0x20
[ 1558.178669][ C1] DEBUG: holding rtnl_mutex for 536 jiffies.
[ 1558.184806][ C1] task:syz-executor.3 state:R running task stack:25968 pid:6351 tgid:6345 ppid:6200 flags:0x00004006
[ 1558.196699][ C1] Call Trace:
[ 1558.200068][ C1] <TASK>
[ 1558.203055][ C1] __schedule+0x17e8/0x4a20
[ 1558.207638][ C1] ? __pfx___schedule+0x10/0x10
[ 1558.212585][ C1] ? lockdep_hardirqs_on_prepare+0x43d/0x780
[ 1558.218675][ C1] ? preempt_schedule_irq+0xf0/0x1c0
[ 1558.224004][ C1] preempt_schedule_irq+0xfb/0x1c0
[ 1558.229196][ C1] ? __pfx_preempt_schedule_irq+0x10/0x10
[ 1558.234986][ C1] irqentry_exit+0x5e/0x90
[ 1558.239503][ C1] asm_sysvec_reschedule_ipi+0x1a/0x20
[ 1104.439430][ C0] DEBUG: holding rtnl_mutex for 578 jiffies.
[ 1104.445729][ C0] task:kworker/u8:3 state:R running task stack:18544 pid:53 tgid:53 ppid:2 flags:0x00004000
[ 1104.459070][ C0] Workqueue: netns cleanup_net
[ 1104.464170][ C0] Call Trace:
[ 1104.467478][ C0] <TASK>
[ 1104.470481][ C0] __schedule+0x17e8/0x4a20
[ 1104.476080][ C0] ? mark_lock+0x9a/0x360
[ 1104.480776][ C0] ? __lock_acquire+0x1359/0x2000
[ 1104.486043][ C0] ? __pfx___schedule+0x10/0x10
[ 1104.490987][ C0] ? lockdep_hardirqs_on_prepare+0x43d/0x780
[ 1104.497017][ C0] ? preempt_schedule_irq+0xf0/0x1c0
[ 1104.502486][ C0] preempt_schedule_irq+0xfb/0x1c0
[ 1104.507809][ C0] ? __pfx_preempt_schedule_irq+0x10/0x10
[ 1104.514030][ C0] irqentry_exit+0x5e/0x90
[ 1104.518689][ C0] asm_sysvec_reschedule_ipi+0x1a/0x20
[ 926.207053][ C1] DEBUG: holding rtnl_mutex for 517 jiffies.
[ 926.213142][ C1] task:syz.1.1365 state:R running task stack:24672 pid:11152 tgid:11152 ppid:10992 flags:0x00004006
[ 926.225053][ C1] Call Trace:
[ 926.228434][ C1] <TASK>
[ 926.231441][ C1] __schedule+0x17e8/0x4a20
[ 926.236054][ C1] ? __pfx___schedule+0x10/0x10
[ 926.241130][ C1] ? lockdep_hardirqs_on_prepare+0x43d/0x780
[ 926.247265][ C1] ? kasan_save_track+0x51/0x80
[ 926.252225][ C1] ? preempt_schedule_irq+0xf0/0x1c0
[ 926.257705][ C1] preempt_schedule_irq+0xfb/0x1c0
[ 926.262899][ C1] ? __pfx_preempt_schedule_irq+0x10/0x10
[ 926.268725][ C1] ? __pfx_pfifo_fast_destroy+0x10/0x10
[ 926.274379][ C1] irqentry_exit+0x5e/0x90
[ 926.278903][ C1] asm_sysvec_apic_timer_interrupt+0x1a/0x20
[ 940.917894][ C0] DEBUG: holding rtnl_mutex for 1611 jiffies.
[ 940.924066][ C0] task:syz.2.2274 state:R running task stack:24336 pid:15954 tgid:15954 ppid:14850 flags:0x00004006
[ 940.936192][ C0] Call Trace:
[ 940.939550][ C0] <TASK>
[ 940.942540][ C0] __schedule+0x17e8/0x4a20
[ 940.947134][ C0] ? __pfx___schedule+0x10/0x10
[ 940.952070][ C0] ? lockdep_hardirqs_on_prepare+0x43d/0x780
[ 940.958362][ C0] ? kasan_save_track+0x51/0x80
[ 940.963266][ C0] ? preempt_schedule_irq+0xf0/0x1c0
[ 940.968628][ C0] preempt_schedule_irq+0xfb/0x1c0
[ 940.973790][ C0] ? __pfx_preempt_schedule_irq+0x10/0x10
[ 940.979610][ C0] ? __pfx_pfifo_fast_destroy+0x10/0x10
[ 940.985227][ C0] irqentry_exit+0x5e/0x90
[ 940.989731][ C0] asm_sysvec_apic_timer_interrupt+0x1a/0x20
[ 2120.744289][ C1] DEBUG: holding rtnl_mutex for 1675 jiffies.
[ 2120.750440][ C1] task:syz-executor state:R running task stack:20288 pid:2431 tgid:2431 ppid:1 flags:0x00004006
[ 2120.762291][ C1] Call Trace:
[ 2120.765647][ C1] <TASK>
[ 2120.768615][ C1] __schedule+0x17e8/0x4a20
[ 2120.773210][ C1] ? __pfx___schedule+0x10/0x10
[ 2120.778152][ C1] ? lockdep_hardirqs_on_prepare+0x43d/0x780
[ 2120.784188][ C1] ? kasan_save_track+0x51/0x80
[ 2120.789118][ C1] ? preempt_schedule_irq+0xf0/0x1c0
[ 2120.794445][ C1] preempt_schedule_irq+0xfb/0x1c0
[ 2120.799621][ C1] ? __pfx_preempt_schedule_irq+0x10/0x10
[ 2120.805378][ C1] ? kvm_kick_cpu+0x26/0xb0
[ 2120.809965][ C1] irqentry_exit+0x5e/0x90
[ 2120.814423][ C1] asm_sysvec_apic_timer_interrupt+0x1a/0x20
[ 1465.514982][ C1] DEBUG: holding rtnl_mutex for 583 jiffies.
[ 1465.521071][ C1] task:kworker/u8:2 state:R running task stack:20232 pid:35 tgid:35 ppid:2 flags:0x00004000
[ 1465.532945][ C1] Workqueue: netns cleanup_net
[ 1465.537846][ C1] Call Trace:
[ 1465.541164][ C1] <TASK>
[ 1465.544132][ C1] __schedule+0x17e8/0x4a20
[ 1465.548730][ C1] ? mark_lock+0x9a/0x360
[ 1465.553148][ C1] ? lockdep_hardirqs_on_prepare+0x43d/0x780
[ 1465.559257][ C1] ? __pfx_lockdep_hardirqs_on_prepare+0x10/0x10
[ 1465.565697][ C1] ? __pfx___schedule+0x10/0x10
[ 1465.570636][ C1] ? lockdep_hardirqs_on+0x99/0x150
[ 1465.575968][ C1] ? mark_lock+0x9a/0x360
[ 1465.580381][ C1] preempt_schedule_irq+0xfb/0x1c0
[ 1465.585599][ C1] ? __pfx_preempt_schedule_irq+0x10/0x10
[ 1465.591383][ C1] irqentry_exit+0x5e/0x90
[ 1465.595895][ C1] asm_sysvec_reschedule_ipi+0x1a/0x20
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [syzbot] [kernel?] KASAN: stack-out-of-bounds Read in __show_regs (2)
[not found] ` <CA+fCnZfxCWZYX-7vJzMcwN4vKguuskk5rGYA2Ntotw=owOZ6Sg@mail.gmail.com>
@ 2024-07-02 15:21 ` Tetsuo Handa
2024-07-07 10:32 ` Tetsuo Handa
0 siblings, 1 reply; 8+ messages in thread
From: Tetsuo Handa @ 2024-07-02 15:21 UTC (permalink / raw)
To: Andrey Konovalov
Cc: syzbot, linux-kernel, syzkaller-bugs, kasan-dev, linux-mm, bp,
dave.hansen, hpa, mingo, tglx, x86
On 2024/07/02 23:29, Andrey Konovalov wrote:
> One other thing that comes to mind with regards to your patch: if the
> task is still executing, the location of things on its stack might
> change due to CONFIG_RANDOMIZE_KSTACK_OFFSET while you're printing the
> task info. However, if the task is sleeping on a lock, this shouldn't
> happen... But maybe a task can wake up during sched_show_task() and
> start handling a new syscall? Just some guesses.
https://syzkaller.appspot.com/bug?extid=d7491e9e156404745fbb says that
this bug happens without my patch. It seems that this bug happens when
printing registers of a preempted thread. 5.15 kernel does not have
CONFIG_RANDOMIZE_KSTACK_OFFSET config option, but
__schedule()
preempt_schedule_irq()
irqentry_exit_cond_resched()
irqentry_exit()
pattern in 5.15 resembles
__schedule()
preempt_schedule_irq()
irqentry_exit()
pattern in linux-next.
[ 1008.224617][T14487] task:syz-executor.1 state:R running task stack:22256 pid:14483 ppid: 434 flags:0x00004000
[ 1008.224656][T14487] Call Trace:
[ 1008.224661][T14487] <TASK>
[ 1008.224669][T14487] __schedule+0xcbe/0x1580
[ 1008.224689][T14487] ? __sched_text_start+0x8/0x8
[ 1008.224709][T14487] ? ttwu_do_activate+0x15d/0x280
[ 1008.224732][T14487] ? _raw_spin_unlock_irqrestore+0x5c/0x80
[ 1008.224758][T14487] preempt_schedule_irq+0xc7/0x140
[ 1008.224781][T14487] ? __cond_resched+0x20/0x20
[ 1008.224802][T14487] ? try_invoke_on_locked_down_task+0x2a0/0x2a0
[ 1008.224829][T14487] irqentry_exit_cond_resched+0x2a/0x30
[ 1008.224851][T14487] irqentry_exit+0x30/0x40
[ 1008.224874][T14487] sysvec_apic_timer_interrupt+0x55/0xc0
[ 1008.224900][T14487] asm_sysvec_apic_timer_interrupt+0x1b/0x20
[ 1008.224923][T14487] RIP: 0010:preempt_schedule_thunk+0x5/0x18
[ 1008.224950][T14487] Code: fd 85 db 0f 84 98 00 00 00 44 8d 73 01 44 89 f6 09 de bf ff ff ff ff e8 47 e4 8f fd 41 09 de 0f 88 88 00 00 00 e8 89 e0 8f fd <4c> 89 e0 48 c1 e8 03 48 b9 00 00 00 00 00 fc ff df 0f b6 04 08 84
[ 1008.224970][T14487] RSP: 0000:0000000000000001 EFLAGS: 00000000 ORIG_RAX: 0000000000000000
[ 1008.224991][T14487] RAX: ffff88811532d948 RBX: ffffc900072ef560 RCX: ffffc900077e7680
[ 1008.225009][T14487] RDX: ffffc900072ef5b0 RSI: ffffffff8100817a RDI: dffffc0000000001
[ 1008.225027][T14487] RBP: 0000000000000001 R08: ffff88811532d948 R09: ffffc900077e7690
[ 1008.225043][T14487] R10: 1ffff92000efced2 R11: ffffffff84bfe126 R12: ffffc900077e7680
[ 1008.225062][T14487] ==================================================================
[ 1008.225071][T14487] BUG: KASAN: stack-out-of-bounds in __show_regs+0x252/0x4d0
[ 1008.225098][T14487] Read of size 8 at addr ffffc900072ef4f8 by task syz-executor.3/14487
[ 1008.225117][T14487]
[ 1008.225123][T14487] CPU: 0 PID: 14487 Comm: syz-executor.3 Not tainted 5.15.118-syzkaller-01748-g241da2ad5601 #0
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [syzbot] [kernel?] KASAN: stack-out-of-bounds Read in __show_regs (2)
2024-07-02 15:21 ` Tetsuo Handa
@ 2024-07-07 10:32 ` Tetsuo Handa
0 siblings, 0 replies; 8+ messages in thread
From: Tetsuo Handa @ 2024-07-07 10:32 UTC (permalink / raw)
To: Alexander Potapenko, Marco Elver, Dmitry Vyukov
Cc: syzbot, linux-kernel, syzkaller-bugs, kasan-dev, linux-mm, bp,
dave.hansen, hpa, mingo, tglx, x86, Andrey Konovalov
Guessing from IRQ entry hint, I found
commit 37ad4ee83642 ("x86: kmsan: don't instrument stack walking functions") and
commit 6cae637fa26d ("entry: kmsan: introduce kmsan_unpoison_entry_regs()").
I guess that we need to disable KASAN for the same reason as well as KMSAN.
Alexander, can you write a patch description for below change?
diff --git a/arch/x86/kernel/dumpstack.c b/arch/x86/kernel/dumpstack.c
index a7d562697e50..01edff4a9d6b 100644
--- a/arch/x86/kernel/dumpstack.c
+++ b/arch/x86/kernel/dumpstack.c
@@ -192,6 +192,9 @@ static void show_trace_log_lvl(struct task_struct *task, struct pt_regs *regs,
int graph_idx = 0;
bool partial = false;
+ /* As with KMSAN, disable KASAN for the same reason. */
+ kasan_disable_current();
+
printk("%sCall Trace:\n", log_lvl);
unwind_start(&state, task, regs, stack);
@@ -304,6 +307,8 @@ static void show_trace_log_lvl(struct task_struct *task, struct pt_regs *regs,
if (stack_name)
printk("%s </%s>\n", log_lvl, stack_name);
}
+
+ kasan_enable_current();
}
void show_stack(struct task_struct *task, unsigned long *sp,
On 2024/07/03 0:21, Tetsuo Handa wrote:
> On 2024/07/02 23:29, Andrey Konovalov wrote:
>> One other thing that comes to mind with regards to your patch: if the
>> task is still executing, the location of things on its stack might
>> change due to CONFIG_RANDOMIZE_KSTACK_OFFSET while you're printing the
>> task info. However, if the task is sleeping on a lock, this shouldn't
>> happen... But maybe a task can wake up during sched_show_task() and
>> start handling a new syscall? Just some guesses.
>
> https://syzkaller.appspot.com/bug?extid=d7491e9e156404745fbb says that
> this bug happens without my patch. It seems that this bug happens when
> printing registers of a preempted thread. 5.15 kernel does not have
> CONFIG_RANDOMIZE_KSTACK_OFFSET config option, but
>
> __schedule()
> preempt_schedule_irq()
> irqentry_exit_cond_resched()
> irqentry_exit()
>
> pattern in 5.15 resembles
>
> __schedule()
> preempt_schedule_irq()
> irqentry_exit()
>
> pattern in linux-next.
>
> [ 1008.224617][T14487] task:syz-executor.1 state:R running task stack:22256 pid:14483 ppid: 434 flags:0x00004000
> [ 1008.224656][T14487] Call Trace:
> [ 1008.224661][T14487] <TASK>
> [ 1008.224669][T14487] __schedule+0xcbe/0x1580
> [ 1008.224689][T14487] ? __sched_text_start+0x8/0x8
> [ 1008.224709][T14487] ? ttwu_do_activate+0x15d/0x280
> [ 1008.224732][T14487] ? _raw_spin_unlock_irqrestore+0x5c/0x80
> [ 1008.224758][T14487] preempt_schedule_irq+0xc7/0x140
> [ 1008.224781][T14487] ? __cond_resched+0x20/0x20
> [ 1008.224802][T14487] ? try_invoke_on_locked_down_task+0x2a0/0x2a0
> [ 1008.224829][T14487] irqentry_exit_cond_resched+0x2a/0x30
> [ 1008.224851][T14487] irqentry_exit+0x30/0x40
> [ 1008.224874][T14487] sysvec_apic_timer_interrupt+0x55/0xc0
> [ 1008.224900][T14487] asm_sysvec_apic_timer_interrupt+0x1b/0x20
> [ 1008.224923][T14487] RIP: 0010:preempt_schedule_thunk+0x5/0x18
> [ 1008.224950][T14487] Code: fd 85 db 0f 84 98 00 00 00 44 8d 73 01 44 89 f6 09 de bf ff ff ff ff e8 47 e4 8f fd 41 09 de 0f 88 88 00 00 00 e8 89 e0 8f fd <4c> 89 e0 48 c1 e8 03 48 b9 00 00 00 00 00 fc ff df 0f b6 04 08 84
> [ 1008.224970][T14487] RSP: 0000:0000000000000001 EFLAGS: 00000000 ORIG_RAX: 0000000000000000
> [ 1008.224991][T14487] RAX: ffff88811532d948 RBX: ffffc900072ef560 RCX: ffffc900077e7680
> [ 1008.225009][T14487] RDX: ffffc900072ef5b0 RSI: ffffffff8100817a RDI: dffffc0000000001
> [ 1008.225027][T14487] RBP: 0000000000000001 R08: ffff88811532d948 R09: ffffc900077e7690
> [ 1008.225043][T14487] R10: 1ffff92000efced2 R11: ffffffff84bfe126 R12: ffffc900077e7680
> [ 1008.225062][T14487] ==================================================================
> [ 1008.225071][T14487] BUG: KASAN: stack-out-of-bounds in __show_regs+0x252/0x4d0
> [ 1008.225098][T14487] Read of size 8 at addr ffffc900072ef4f8 by task syz-executor.3/14487
> [ 1008.225117][T14487]
> [ 1008.225123][T14487] CPU: 0 PID: 14487 Comm: syz-executor.3 Not tainted 5.15.118-syzkaller-01748-g241da2ad5601 #0
>
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [syzbot] [kernel?] KASAN: stack-out-of-bounds Read in __show_regs (2)
[not found] <000000000000a8c856061ae85e20@google.com>
2024-06-25 1:22 ` [syzbot] [kernel?] KASAN: stack-out-of-bounds Read in __show_regs (2) Tetsuo Handa
@ 2024-08-01 23:39 ` syzbot
1 sibling, 0 replies; 8+ messages in thread
From: syzbot @ 2024-08-01 23:39 UTC (permalink / raw)
To: andreyknvl, bp, dave.hansen, dvyukov, elver, glider, hpa,
kasan-dev, linux-kernel, linux-mm, mingo, penguin-kernel,
syzkaller-bugs, tglx, x86
syzbot has found a reproducer for the following issue on:
HEAD commit: 931a3b3bccc9 Add linux-next specific files for 20240729
git tree: linux-next
console output: https://syzkaller.appspot.com/x/log.txt?x=10f2388d980000
kernel config: https://syzkaller.appspot.com/x/.config?x=91dc4a647da4c251
dashboard link: https://syzkaller.appspot.com/bug?extid=e9be5674af5e3a0b9ecc
compiler: Debian clang version 15.0.6, GNU ld (GNU Binutils for Debian) 2.40
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=16efaf11980000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=10f437f1980000
Downloadable assets:
disk image: https://storage.googleapis.com/syzbot-assets/6b83209c369b/disk-931a3b3b.raw.xz
vmlinux: https://storage.googleapis.com/syzbot-assets/a5b0c2d893d4/vmlinux-931a3b3b.xz
kernel image: https://storage.googleapis.com/syzbot-assets/5b3ee6d54a9b/bzImage-931a3b3b.xz
IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+e9be5674af5e3a0b9ecc@syzkaller.appspotmail.com
RIP: 0010:minstrel_ht_fill_rate_array net/mac80211/rc80211_minstrel_ht.c:1883 [inline]
RIP: 0010:minstrel_ht_init_cck_rates net/mac80211/rc80211_minstrel_ht.c:1909 [inline]
RIP: 0010:minstrel_ht_alloc+0x299/0x860 net/mac80211/rc80211_minstrel_ht.c:1962
Code: 4c 24 08 45 31 ed 4c 89 f8 48 c1 e8 03 42 0f b6 04 30 84 c0 0f 85 f1 00 00 00 41 8b 6c 24 fc 21 dd 89 ef 89 de e8 17 f5 48 f6 <39> dd 75 4c 49 8d 7f 04 48 89 f8 48 c1 e8 03 42 0f b6 04 30 84 c0
RSP: dc9b:0000000000000007 EFLAGS: 00000007 ORIG_RAX: ffffc90003606e70
==================================================================
BUG: KASAN: stack-out-of-bounds in __show_regs+0xc1/0x610 arch/x86/kernel/process_64.c:83
Read of size 8 at addr ffffc90003606ea0 by task swapper/0/0
CPU: 0 UID: 0 PID: 0 Comm: swapper/0 Not tainted 6.11.0-rc1-next-20240729-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/27/2024
Call Trace:
<IRQ>
__dump_stack lib/dump_stack.c:94 [inline]
dump_stack_lvl+0x241/0x360 lib/dump_stack.c:120
print_address_description mm/kasan/report.c:377 [inline]
print_report+0x169/0x550 mm/kasan/report.c:488
kasan_report+0x143/0x180 mm/kasan/report.c:601
__show_regs+0xc1/0x610 arch/x86/kernel/process_64.c:83
show_trace_log_lvl+0x3d4/0x520 arch/x86/kernel/dumpstack.c:301
sched_show_task+0x506/0x6d0 kernel/sched/core.c:7512
report_rtnl_holders+0x327/0x400 net/core/rtnetlink.c:110
call_timer_fn+0x18e/0x650 kernel/time/timer.c:1792
expire_timers kernel/time/timer.c:1843 [inline]
__run_timers kernel/time/timer.c:2417 [inline]
__run_timer_base+0x66a/0x8e0 kernel/time/timer.c:2428
run_timer_base kernel/time/timer.c:2437 [inline]
run_timer_softirq+0xb7/0x170 kernel/time/timer.c:2447
handle_softirqs+0x2c4/0x970 kernel/softirq.c:554
__do_softirq kernel/softirq.c:588 [inline]
invoke_softirq kernel/softirq.c:428 [inline]
__irq_exit_rcu+0xf4/0x1c0 kernel/softirq.c:637
irq_exit_rcu+0x9/0x30 kernel/softirq.c:649
instr_sysvec_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1043 [inline]
sysvec_apic_timer_interrupt+0xa6/0xc0 arch/x86/kernel/apic/apic.c:1043
</IRQ>
<TASK>
asm_sysvec_apic_timer_interrupt+0x1a/0x20 arch/x86/include/asm/idtentry.h:702
RIP: 0010:flush_smp_call_function_queue+0x23f/0x2a0 kernel/smp.c:592
Code: 00 4d 85 f6 75 16 e8 40 4f 0c 00 eb 15 e8 39 4f 0c 00 e8 c4 19 32 0a 4d 85 f6 74 ea e8 2a 4f 0c 00 fb 48 c7 04 24 0e 36 e0 45 <4b> c7 04 27 00 00 00 00 66 43 c7 44 27 09 00 00 43 c6 44 27 0b 00
RSP: 0018:ffffffff8e607cc0 EFLAGS: 00000293
RAX: ffffffff81877c36 RBX: 0000000000000000 RCX: ffffffff8e694680
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
RBP: ffffffff8e607d70 R08: ffffffff81877c0c R09: 1ffffffff202faed
R10: dffffc0000000000 R11: fffffbfff202faee R12: 1ffffffff1cc0f98
R13: 0000000000000046 R14: 0000000000000200 R15: dffffc0000000000
do_idle+0x565/0x5d0 kernel/sched/idle.c:353
cpu_startup_entry+0x42/0x60 kernel/sched/idle.c:424
rest_init+0x2dc/0x300 init/main.c:747
start_kernel+0x47a/0x500 init/main.c:1103
x86_64_start_reservations+0x2a/0x30 arch/x86/kernel/head64.c:507
x86_64_start_kernel+0x9f/0xa0 arch/x86/kernel/head64.c:488
common_startup_64+0x13e/0x147
</TASK>
The buggy address belongs to the virtual mapping at
[ffffc90003600000, ffffc90003609000) created by:
copy_process+0x5d1/0x3d90 kernel/fork.c:2206
The buggy address belongs to the physical page:
page: refcount:1 mapcount:0 mapping:0000000000000000 index:0x0 pfn:0x7fbc5
flags: 0xfff00000000000(node=0|zone=1|lastcpupid=0x7ff)
raw: 00fff00000000000 0000000000000000 dead000000000122 0000000000000000
raw: 0000000000000000 0000000000000000 00000001ffffffff 0000000000000000
page dumped because: kasan: bad access detected
page_owner tracks the page as allocated
page last allocated via order 0, migratetype Unmovable, gfp_mask 0x2dc2(GFP_KERNEL|__GFP_HIGHMEM|__GFP_NOWARN|__GFP_ZERO), pid 5241, tgid 5241 (syz-executor243), ts 226123633416, free_ts 218311192673
set_page_owner include/linux/page_owner.h:32 [inline]
post_alloc_hook+0x1f3/0x230 mm/page_alloc.c:1493
prep_new_page mm/page_alloc.c:1501 [inline]
get_page_from_freelist+0x2e4c/0x2f10 mm/page_alloc.c:3442
__alloc_pages_noprof+0x256/0x6c0 mm/page_alloc.c:4700
alloc_pages_mpol_noprof+0x3e8/0x680 mm/mempolicy.c:2263
vm_area_alloc_pages mm/vmalloc.c:3584 [inline]
__vmalloc_area_node mm/vmalloc.c:3660 [inline]
__vmalloc_node_range_noprof+0x971/0x1460 mm/vmalloc.c:3841
alloc_thread_stack_node kernel/fork.c:314 [inline]
dup_task_struct+0x444/0x8c0 kernel/fork.c:1115
copy_process+0x5d1/0x3d90 kernel/fork.c:2206
kernel_clone+0x226/0x8f0 kernel/fork.c:2788
__do_sys_clone kernel/fork.c:2931 [inline]
__se_sys_clone kernel/fork.c:2915 [inline]
__x64_sys_clone+0x258/0x2a0 kernel/fork.c:2915
do_syscall_x64 arch/x86/entry/common.c:52 [inline]
do_syscall_64+0xf3/0x230 arch/x86/entry/common.c:83
entry_SYSCALL_64_after_hwframe+0x77/0x7f
page last free pid 5231 tgid 5231 stack trace:
reset_page_owner include/linux/page_owner.h:25 [inline]
free_pages_prepare mm/page_alloc.c:1094 [inline]
free_unref_page+0xd22/0xea0 mm/page_alloc.c:2612
__folio_put+0x2c8/0x440 mm/swap.c:128
pipe_buf_release include/linux/pipe_fs_i.h:219 [inline]
pipe_update_tail fs/pipe.c:224 [inline]
pipe_read+0x6f2/0x13e0 fs/pipe.c:344
new_sync_read fs/read_write.c:395 [inline]
vfs_read+0x9bd/0xbc0 fs/read_write.c:476
ksys_read+0x1a0/0x2c0 fs/read_write.c:619
do_syscall_x64 arch/x86/entry/common.c:52 [inline]
do_syscall_64+0xf3/0x230 arch/x86/entry/common.c:83
entry_SYSCALL_64_after_hwframe+0x77/0x7f
Memory state around the buggy address:
ffffc90003606d80: 00 f3 f3 f3 f3 f3 f3 f3 00 00 00 00 00 00 00 00
ffffc90003606e00: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
>ffffc90003606e80: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
^
ffffc90003606f00: f1 f1 f1 f1 00 00 00 00 00 00 00 00 f3 f3 f3 f3
ffffc90003606f80: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
==================================================================
----------------
Code disassembly (best guess):
0: 4c 24 08 rex.WR and $0x8,%al
3: 45 31 ed xor %r13d,%r13d
6: 4c 89 f8 mov %r15,%rax
9: 48 c1 e8 03 shr $0x3,%rax
d: 42 0f b6 04 30 movzbl (%rax,%r14,1),%eax
12: 84 c0 test %al,%al
14: 0f 85 f1 00 00 00 jne 0x10b
1a: 41 8b 6c 24 fc mov -0x4(%r12),%ebp
1f: 21 dd and %ebx,%ebp
21: 89 ef mov %ebp,%edi
23: 89 de mov %ebx,%esi
25: e8 17 f5 48 f6 call 0xf648f541
* 2a: 39 dd cmp %ebx,%ebp <-- trapping instruction
2c: 75 4c jne 0x7a
2e: 49 8d 7f 04 lea 0x4(%r15),%rdi
32: 48 89 f8 mov %rdi,%rax
35: 48 c1 e8 03 shr $0x3,%rax
39: 42 0f b6 04 30 movzbl (%rax,%r14,1),%eax
3e: 84 c0 test %al,%al
---
If you want syzbot to run the reproducer, reply with:
#syz test: git://repo/address.git branch-or-commit-hash
If you attach or paste a git patch, syzbot will apply it before testing.
^ permalink raw reply [flat|nested] 8+ messages in thread
end of thread, other threads:[~2024-08-01 23:39 UTC | newest]
Thread overview: 8+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
[not found] <000000000000a8c856061ae85e20@google.com>
2024-06-25 1:22 ` [syzbot] [kernel?] KASAN: stack-out-of-bounds Read in __show_regs (2) Tetsuo Handa
2024-07-01 12:43 ` Tetsuo Handa
2024-07-01 15:10 ` Andrey Konovalov
2024-07-02 6:11 ` Tetsuo Handa
2024-07-02 7:05 ` Tetsuo Handa
[not found] ` <CA+fCnZfxCWZYX-7vJzMcwN4vKguuskk5rGYA2Ntotw=owOZ6Sg@mail.gmail.com>
2024-07-02 15:21 ` Tetsuo Handa
2024-07-07 10:32 ` Tetsuo Handa
2024-08-01 23:39 ` syzbot
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox