lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [day] [month] [year] [list]
Message-ID: <202401291521.1322c280-oliver.sang@intel.com>
Date: Mon, 29 Jan 2024 16:02:57 +0800
From: kernel test robot <oliver.sang@...el.com>
To: Steven Rostedt <rostedt@...dmis.org>
CC: <oe-lkp@...ts.linux.dev>, <lkp@...el.com>, <linux-kernel@...r.kernel.org>,
	Mark Rutland <mark.rutland@....com>, Beau Belgrave
	<beaub@...ux.microsoft.com>, Masami Hiramatsu <mhiramat@...nel.org>,
	<linux-trace-kernel@...r.kernel.org>, <oliver.sang@...el.com>
Subject: [linus:master] [tracing]  bb32500fb9:
 BUG:KASAN:slab-use-after-free_in_tracing_open_file_tr



Hello,

kernel test robot noticed "BUG:KASAN:slab-use-after-free_in_tracing_open_file_tr" on:

commit: bb32500fb9b78215e4ef6ee8b4345c5f5d7eafb4 ("tracing: Have trace_event_file have ref counters")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master

[test failed on linus/master ecb1b8288dc7ccbdcb3b9df005fa1c0e0c0388a7]
[test failed on linux-next/master 01af33cc9894b4489fb68fa35c40e9fe85df63dc]

in testcase: kernel-selftests
version: kernel-selftests-x86_64-60acb023-1_20230329
with following parameters:

	group: user_events



compiler: gcc-12
test machine: 36 threads 1 sockets Intel(R) Core(TM) i9-10980XE CPU @ 3.00GHz (Cascade Lake) with 32G memory

(please refer to attached dmesg/kmsg for entire log/backtrace)


we noticed this issue is random (6 out of 20 runs as below).

at the same time, we also observed there is an issue
"dmesg.BUG:KASAN:slab-use-after-free_in_event_enable_write"
always happens on parent in all 20 runs.

the parent dmesg is attached FYI.


dcc4e5728eeaeda8 bb32500fb9b78215e4ef6ee8b43
---------------- ---------------------------
       fail:runs  %reproduction    fail:runs
           |             |             |
         20:20        -100%            :20    dmesg.BUG:KASAN:slab-use-after-free_in_event_enable_write
           :20          30%           6:20    dmesg.BUG:KASAN:slab-use-after-free_in_tracing_open_file_tr



If you fix the issue in a separate patch/commit (i.e. not just a new version of
the same patch/commit), kindly add following tags
| Reported-by: kernel test robot <oliver.sang@...el.com>
| Closes: https://lore.kernel.org/oe-lkp/202401291521.1322c280-oliver.sang@intel.com


[ 108.154115][ T2177] BUG: KASAN: slab-use-after-free in tracing_open_file_tr (kernel/trace/trace.c:4984) 
[  108.154911][ T2177] Read of size 8 at addr ffff888273293a50 by task ftrace_test/2177
[  108.155680][ T2177]
[  108.156009][ T2177] CPU: 8 PID: 2177 Comm: ftrace_test Not tainted 6.6.0-rc4-00021-gbb32500fb9b7 #1
[  108.156886][ T2177] Hardware name: Gigabyte Technology Co., Ltd. X299 UD4 Pro/X299 UD4 Pro-CF, BIOS F8a 04/27/2021
[  108.157878][ T2177] Call Trace:
[  108.158275][ T2177]  <TASK>
[ 108.158650][ T2177] dump_stack_lvl (lib/dump_stack.c:108) 
[ 108.159135][ T2177] print_address_description+0x2c/0x3a0 
[ 108.159775][ T2177] ? tracing_open_file_tr (kernel/trace/trace.c:4984) 
[ 108.160351][ T2177] print_report (mm/kasan/report.c:476) 
[ 108.160795][ T2177] ? kasan_addr_to_slab (mm/kasan/common.c:35) 
[ 108.161279][ T2177] ? tracing_open_file_tr (kernel/trace/trace.c:4984) 
[ 108.161798][ T2177] kasan_report (mm/kasan/report.c:590) 
[ 108.162246][ T2177] ? tracing_open_file_tr (kernel/trace/trace.c:4984) 
[ 108.162768][ T2177] tracing_open_file_tr (kernel/trace/trace.c:4984) 
[ 108.163277][ T2177] do_dentry_open (fs/open.c:929) 
[ 108.163750][ T2177] ? tracing_is_disabled (kernel/trace/trace.c:4973) 
[ 108.164257][ T2177] ? may_open (fs/namei.c:3268) 
[ 108.164686][ T2177] do_open (fs/namei.c:3639) 
[ 108.165105][ T2177] path_openat (fs/namei.c:3797) 
[ 108.165549][ T2177] ? path_lookupat (fs/namei.c:3778) 
[ 108.166018][ T2177] ? __lock_acquire (kernel/locking/lockdep.c:5136) 
[ 108.166513][ T2177] do_filp_open (fs/namei.c:3823) 
[ 108.166974][ T2177] ? may_open_dev (fs/namei.c:3817) 
[ 108.167425][ T2177] ? _raw_spin_unlock (arch/x86/include/asm/preempt.h:95 include/linux/spinlock_api_smp.h:143 kernel/locking/spinlock.c:186) 
[ 108.167910][ T2177] ? alloc_fd (fs/file.c:555 (discriminator 10)) 
[ 108.168361][ T2177] do_sys_openat2 (fs/open.c:1422) 
[ 108.168838][ T2177] ? build_open_flags (fs/open.c:1408) 
[ 108.169333][ T2177] __x64_sys_openat (fs/open.c:1448) 
[ 108.169824][ T2177] ? __x64_sys_open (fs/open.c:1448) 
[ 108.170304][ T2177] ? lockdep_hardirqs_on_prepare (kernel/locking/lockdep.c:4565) 
[ 108.170935][ T2177] ? syscall_enter_from_user_mode (arch/x86/include/asm/irqflags.h:42 arch/x86/include/asm/irqflags.h:77 kernel/entry/common.c:111) 
[ 108.171545][ T2177] do_syscall_64 (arch/x86/entry/common.c:50 arch/x86/entry/common.c:80) 
[ 108.172051][ T2177] entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:120) 
[  108.172672][ T2177] RIP: 0033:0x7f955d2e6e51
[ 108.173166][ T2177] Code: 75 57 89 f0 25 00 00 41 00 3d 00 00 41 00 74 49 80 3d 9a 27 0e 00 00 74 6d 89 da 48 89 ee bf 9c ff ff ff b8 01 01 00 00 0f 05 <48> 3d 00 f0 ff ff 0f 87 93 00 00 00 48 8b 54 24 28 64 48 2b 14 25
All code
========
   0:	75 57                	jne    0x59
   2:	89 f0                	mov    %esi,%eax
   4:	25 00 00 41 00       	and    $0x410000,%eax
   9:	3d 00 00 41 00       	cmp    $0x410000,%eax
   e:	74 49                	je     0x59
  10:	80 3d 9a 27 0e 00 00 	cmpb   $0x0,0xe279a(%rip)        # 0xe27b1
  17:	74 6d                	je     0x86
  19:	89 da                	mov    %ebx,%edx
  1b:	48 89 ee             	mov    %rbp,%rsi
  1e:	bf 9c ff ff ff       	mov    $0xffffff9c,%edi
  23:	b8 01 01 00 00       	mov    $0x101,%eax
  28:	0f 05                	syscall 
  2a:*	48 3d 00 f0 ff ff    	cmp    $0xfffffffffffff000,%rax		<-- trapping instruction
  30:	0f 87 93 00 00 00    	ja     0xc9
  36:	48 8b 54 24 28       	mov    0x28(%rsp),%rdx
  3b:	64                   	fs
  3c:	48                   	rex.W
  3d:	2b                   	.byte 0x2b
  3e:	14 25                	adc    $0x25,%al

Code starting with the faulting instruction
===========================================
   0:	48 3d 00 f0 ff ff    	cmp    $0xfffffffffffff000,%rax
   6:	0f 87 93 00 00 00    	ja     0x9f
   c:	48 8b 54 24 28       	mov    0x28(%rsp),%rdx
  11:	64                   	fs
  12:	48                   	rex.W
  13:	2b                   	.byte 0x2b
  14:	14 25                	adc    $0x25,%al
[  108.174927][ T2177] RSP: 002b:00007ffd1c637260 EFLAGS: 00000202 ORIG_RAX: 0000000000000101
[  108.175759][ T2177] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f955d2e6e51
[  108.176539][ T2177] RDX: 0000000000000000 RSI: 000055b82b59e6e8 RDI: 00000000ffffff9c
[  108.177333][ T2177] RBP: 000055b82b59e6e8 R08: 0000000000000007 R09: 000055b82cfcc2b0
[  108.178119][ T2177] R10: 0000000000000000 R11: 0000000000000202 R12: 0000000000000000
[  108.178896][ T2177] R13: 00007ffd1c637898 R14: 000055b82b5a0dc8 R15: 00007f955d4f0020
[  108.179680][ T2177]  </TASK>
[  108.180055][ T2177]
[  108.180383][ T2177] Allocated by task 2177:
[ 108.180856][ T2177] kasan_save_stack (mm/kasan/common.c:46) 
[ 108.181356][ T2177] kasan_set_track (mm/kasan/common.c:52) 
[ 108.181825][ T2177] __kasan_slab_alloc (mm/kasan/common.c:328) 
[ 108.182340][ T2177] kmem_cache_alloc (mm/slab.h:762 mm/slub.c:3478 mm/slub.c:3486 mm/slub.c:3493 mm/slub.c:3502) 
[ 108.182884][ T2177] trace_create_new_event (kernel/trace/trace_events.c:2908) 
[ 108.183438][ T2177] trace_add_event_call (kernel/trace/trace_events.c:2974 kernel/trace/trace_events.c:3728 kernel/trace/trace_events.c:3040) 
[ 108.183950][ T2177] user_event_set_call_visible (kernel/trace/trace_events_user.c:1455) 
[ 108.184500][ T2177] user_event_parse (kernel/trace/trace_events_user.c:1908 kernel/trace/trace_events_user.c:2020) 
[ 108.184977][ T2177] user_events_ioctl_reg (kernel/trace/trace_events_user.c:2332) 
[ 108.185496][ T2177] user_events_ioctl (kernel/trace/trace_events_user.c:2528) 
[ 108.185987][ T2177] __x64_sys_ioctl (fs/ioctl.c:52 fs/ioctl.c:871 fs/ioctl.c:857 fs/ioctl.c:857) 
[ 108.186464][ T2177] do_syscall_64 (arch/x86/entry/common.c:50 arch/x86/entry/common.c:80) 
[ 108.186912][ T2177] entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:120) 
[  108.187484][ T2177]
[  108.187761][ T2177] Freed by task 400:
[ 108.188166][ T2177] kasan_save_stack (mm/kasan/common.c:46) 
[ 108.188628][ T2177] kasan_set_track (mm/kasan/common.c:52) 
[ 108.189089][ T2177] kasan_save_free_info (mm/kasan/generic.c:524) 
[ 108.189582][ T2177] __kasan_slab_free (mm/kasan/common.c:238 mm/kasan/common.c:200 mm/kasan/common.c:244) 
[ 108.190078][ T2177] slab_free_freelist_hook (mm/slub.c:1826) 
[ 108.190614][ T2177] kmem_cache_free (mm/slub.c:3809 mm/slub.c:3831) 
[ 108.191092][ T2177] event_remove (kernel/trace/trace_events.c:2609 kernel/trace/trace_events.c:2648) 
[ 108.191551][ T2177] trace_remove_event_call (kernel/trace/trace_events.c:3054 kernel/trace/trace_events.c:3090 kernel/trace/trace_events.c:3110) 
[ 108.192083][ T2177] user_event_set_call_visible (kernel/trace/trace_events_user.c:1457) 
[ 108.192624][ T2177] destroy_user_event (kernel/trace/trace_events_user.c:1474 (discriminator 9)) 
[ 108.193116][ T2177] delayed_destroy_user_event (kernel/trace/trace_events_user.c:239) 
[ 108.193655][ T2177] process_one_work (kernel/workqueue.c:2635) 
[ 108.194151][ T2177] worker_thread (kernel/workqueue.c:2697 kernel/workqueue.c:2784) 
[ 108.194673][ T2177] kthread (kernel/kthread.c:388) 
[ 108.195136][ T2177] ret_from_fork (arch/x86/kernel/process.c:153) 
[ 108.195641][ T2177] ret_from_fork_asm (arch/x86/entry/entry_64.S:312) 
[  108.196148][ T2177]
[  108.196483][ T2177] The buggy address belongs to the object at ffff888273293a08
[  108.196483][ T2177]  which belongs to the cache trace_event_file of size 96
[  108.197819][ T2177] The buggy address is located 72 bytes inside of
[  108.197819][ T2177]  freed 96-byte region [ffff888273293a08, ffff888273293a68)
[  108.199072][ T2177]
[  108.199388][ T2177] The buggy address belongs to the physical page:
[  108.200028][ T2177] page:ffffea0009cca480 refcount:1 mapcount:0 mapping:0000000000000000 index:0xffff888273293e18 pfn:0x273292
[  108.201100][ T2177] head:ffffea0009cca480 order:1 entire_mapcount:0 nr_pages_mapped:0 pincount:0
[  108.201955][ T2177] flags: 0x17ffffc0000840(slab|head|node=0|zone=2|lastcpupid=0x1fffff)
[  108.202751][ T2177] page_type: 0xffffffff()
[  108.203248][ T2177] raw: 0017ffffc0000840 ffff888100053140 ffff8881000550c8 ffff8881000550c8
[  108.204085][ T2177] raw: ffff888273293e18 0000000000270021 00000001ffffffff 0000000000000000
[  108.204926][ T2177] page dumped because: kasan: bad access detected
[  108.205549][ T2177]
[  108.205869][ T2177] Memory state around the buggy address:
[  108.206475][ T2177]  ffff888273293900: fc fc fc fc fc fc fc 00 00 00 00 00 00 00 00 00
[  108.207228][ T2177]  ffff888273293980: 00 00 00 fc fc fc fc fc fc fc fc fc fc fc fc fc
[  108.207978][ T2177] >ffff888273293a00: fc fa fb fb fb fb fb fb fb fb fb fb fb fc fc fc
[  108.208725][ T2177]                                                  ^
[  108.209362][ T2177]  ffff888273293a80: fc fc fc fc fc fc fc fc fc fc fc fa fb fb fb fb
[  108.210109][ T2177]  ffff888273293b00: fb fb fb fb fb fb fb fc fc fc fc fc fc fc fc fc
[  108.210854][ T2177] ==================================================================
[  108.211632][ T2177] Disabling lock debugging due to kernel taint


The kernel config and materials to reproduce are available at:
https://download.01.org/0day-ci/archive/20240129/202401291521.1322c280-oliver.sang@intel.com



-- 
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests/wiki


Download attachment "dmesg-parent.xz" of type "application/x-xz" (32612 bytes)

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ