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>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Date:   Mon, 17 Jan 2022 15:18:34 +0800
From:   kernel test robot <oliver.sang@...el.com>
To:     Ravi Bangoria <ravi.bangoria@....com>
Cc:     0day robot <lkp@...el.com>, Ravi Bangoria <ravi.bangoria@....com>,
        LKML <linux-kernel@...r.kernel.org>, lkp@...ts.01.org,
        peterz@...radead.org, acme@...nel.org,
        alexander.shishkin@...ux.intel.com, jolsa@...hat.com,
        namhyung@...nel.org, songliubraving@...com, eranian@...gle.com,
        alexey.budankov@...ux.intel.com, ak@...ux.intel.com,
        mark.rutland@....com, megha.dey@...el.com, frederic@...nel.org,
        maddy@...ux.ibm.com, irogers@...gle.com, kim.phillips@....com,
        santosh.shukla@....com
Subject: [perf]  f7cf7134e4:
 WARNING:at_kernel/events/core.c:#__pmu_ctx_sched_out



Greeting,

FYI, we noticed the following commit (built with gcc-9):

commit: f7cf7134e405062bf0f22c3ba5637241c4c4d06a ("[RFC v2] perf: Rewrite core context handling")
url: https://github.com/0day-ci/linux/commits/Ravi-Bangoria/perf-Rewrite-core-context-handling/20220113-215022
base: https://git.kernel.org/cgit/linux/kernel/git/tip/tip.git a9f4a6e92b3b319296fb078da2615f618f6cd80c
patch link: https://lore.kernel.org/lkml/20220113134743.1292-1-ravi.bangoria@amd.com

in testcase: trinity
version: trinity-x86_64-608712d8-1_20220112
with following parameters:

	runtime: 300s
	group: group-03

test-description: Trinity is a linux system call fuzz tester.
test-url: http://codemonkey.org.uk/projects/trinity/


on test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G

caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):


+------------------------------------------------------+------------+------------+
|                                                      | a9f4a6e92b | f7cf7134e4 |
+------------------------------------------------------+------------+------------+
| WARNING:at_kernel/events/core.c:#__pmu_ctx_sched_out | 0          | 12         |
| RIP:__pmu_ctx_sched_out                              | 0          | 12         |
+------------------------------------------------------+------------+------------+


If you fix the issue, kindly add following tag
Reported-by: kernel test robot <oliver.sang@...el.com>


[ 61.980728][ T8152] WARNING: CPU: 0 PID: 8152 at kernel/events/core.c:3234 __pmu_ctx_sched_out (kernel/events/core.c:3234 (discriminator 1)) 
[   61.983310][ T8152] Modules linked in: can_bcm can_raw can cn scsi_transport_iscsi ipmi_msghandler sr_mod cdrom sg ata_generic
[   61.986280][ T8152] CPU: 0 PID: 8152 Comm: trinity-c7 Not tainted 5.16.0-rc1-00018-gf7cf7134e405 #1
[   61.988767][ T8152] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[ 61.991025][ T8152] RIP: 0010:__pmu_ctx_sched_out (kernel/events/core.c:3234 (discriminator 1)) 
[ 61.992479][ T8152] Code: 89 fb 4c 8b 2f 49 83 bc 24 88 00 00 00 00 74 24 41 83 7c 24 70 00 75 1c 49 8b 45 48 65 48 03 05 79 a0 e9 7e 48 39 78 60 74 02 <0f> 0b 48 c7 40 60 00 00 00 00 4c 89 ef e8 50 fd ff ff 41 f6 c6 02
All code
========
   0:	89 fb                	mov    %edi,%ebx
   2:	4c 8b 2f             	mov    (%rdi),%r13
   5:	49 83 bc 24 88 00 00 	cmpq   $0x0,0x88(%r12)
   c:	00 00 
   e:	74 24                	je     0x34
  10:	41 83 7c 24 70 00    	cmpl   $0x0,0x70(%r12)
  16:	75 1c                	jne    0x34
  18:	49 8b 45 48          	mov    0x48(%r13),%rax
  1c:	65 48 03 05 79 a0 e9 	add    %gs:0x7ee9a079(%rip),%rax        # 0x7ee9a09d
  23:	7e 
  24:	48 39 78 60          	cmp    %rdi,0x60(%rax)
  28:	74 02                	je     0x2c
  2a:*	0f 0b                	ud2    		<-- trapping instruction
  2c:	48 c7 40 60 00 00 00 	movq   $0x0,0x60(%rax)
  33:	00 
  34:	4c 89 ef             	mov    %r13,%rdi
  37:	e8 50 fd ff ff       	callq  0xfffffffffffffd8c
  3c:	41 f6 c6 02          	test   $0x2,%r14b

Code starting with the faulting instruction
===========================================
   0:	0f 0b                	ud2    
   2:	48 c7 40 60 00 00 00 	movq   $0x0,0x60(%rax)
   9:	00 
   a:	4c 89 ef             	mov    %r13,%rdi
   d:	e8 50 fd ff ff       	callq  0xfffffffffffffd62
  12:	41 f6 c6 02          	test   $0x2,%r14b
[   61.997335][ T8152] RSP: 0018:ffffc9000218fc78 EFLAGS: 00010007
[   61.998976][ T8152] RAX: ffff88842fc2f658 RBX: ffff88812b633000 RCX: 0000000000000001
[   62.000996][ T8152] RDX: 0000000000000000 RSI: 0000000000000003 RDI: ffff88812b633000
[   62.003040][ T8152] RBP: ffff88812b633000 R08: ffff888175700b38 R09: ffff88816c54dc50
[   62.005690][ T8152] R10: ffff8881767fdf00 R11: ffff88810cc004c0 R12: ffff888175700b00
[   62.007781][ T8152] R13: ffffffff829f5580 R14: 0000000000000003 R15: ffff88812b37c600
[   62.009979][ T8152] FS:  00007f72f7208740(0000) GS:ffff88842fc00000(0000) knlGS:0000000000000000
[   62.012266][ T8152] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   62.014072][ T8152] CR2: 00007f72f6ec5efc CR3: 00000001755b6000 CR4: 00000000000006f0
[   62.016206][ T8152] Call Trace:
[   62.017163][ T8152]  <TASK>
[ 62.018032][ T8152] ctx_sched_out (kernel/events/core.c:3314 (discriminator 3)) 
[ 62.019167][ T8152] ctx_resched (kernel/events/core.c:2734) 
[ 62.020303][ T8152] __perf_install_in_context (kernel/events/core.c:2809) 
[ 62.021707][ T8152] ? sw_perf_event_destroy (kernel/events/core.c:72) 
[ 62.023104][ T8152] remote_function (kernel/events/core.c:91 kernel/events/core.c:71) 
[ 62.024448][ T8152] generic_exec_single (arch/x86/include/asm/irqflags.h:127 kernel/smp.c:520 kernel/smp.c:504) 
[ 62.025714][ T8152] ? __alloc_file (fs/file_table.c:117) 
[ 62.027233][ T8152] smp_call_function_single (kernel/smp.c:757) 
[ 62.028756][ T8152] ? sw_perf_event_destroy (kernel/events/core.c:72) 
[ 62.030203][ T8152] ? alloc_file (fs/file_table.c:200) 
[ 62.031351][ T8152] task_function_call (kernel/events/core.c:121) 
[ 62.032654][ T8152] ? ctx_resched (kernel/events/core.c:2762) 
[ 62.033860][ T8152] perf_install_in_context (kernel/events/core.c:2910) 
[ 62.035324][ T8152] __do_sys_perf_event_open (kernel/events/core.c:12491) 
[ 62.036830][ T8152] do_syscall_64 (arch/x86/entry/common.c:50 arch/x86/entry/common.c:80) 
[ 62.038078][ T8152] entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:113) 
[   62.039568][ T8152] RIP: 0033:0x7f72f731ff59
[ 62.040675][ T8152] Code: 00 c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 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 8b 0d 07 6f 0c 00 f7 d8 64 89 01 48
All code
========
   0:	00 c3                	add    %al,%bl
   2:	66 2e 0f 1f 84 00 00 	nopw   %cs:0x0(%rax,%rax,1)
   9:	00 00 00 
   c:	0f 1f 44 00 00       	nopl   0x0(%rax,%rax,1)
  11:	48 89 f8             	mov    %rdi,%rax
  14:	48 89 f7             	mov    %rsi,%rdi
  17:	48 89 d6             	mov    %rdx,%rsi
  1a:	48 89 ca             	mov    %rcx,%rdx
  1d:	4d 89 c2             	mov    %r8,%r10
  20:	4d 89 c8             	mov    %r9,%r8
  23:	4c 8b 4c 24 08       	mov    0x8(%rsp),%r9
  28:	0f 05                	syscall 
  2a:*	48 3d 01 f0 ff ff    	cmp    $0xfffffffffffff001,%rax		<-- trapping instruction
  30:	73 01                	jae    0x33
  32:	c3                   	retq   
  33:	48 8b 0d 07 6f 0c 00 	mov    0xc6f07(%rip),%rcx        # 0xc6f41
  3a:	f7 d8                	neg    %eax
  3c:	64 89 01             	mov    %eax,%fs:(%rcx)
  3f:	48                   	rex.W

Code starting with the faulting instruction
===========================================
   0:	48 3d 01 f0 ff ff    	cmp    $0xfffffffffffff001,%rax
   6:	73 01                	jae    0x9
   8:	c3                   	retq   
   9:	48 8b 0d 07 6f 0c 00 	mov    0xc6f07(%rip),%rcx        # 0xc6f17
  10:	f7 d8                	neg    %eax
  12:	64 89 01             	mov    %eax,%fs:(%rcx)
  15:	48                   	rex.W
[   62.045496][ T8152] RSP: 002b:00007ffddf82c708 EFLAGS: 00000246 ORIG_RAX: 000000000000012a
[   62.047784][ T8152] RAX: ffffffffffffffda RBX: 000000000000012a RCX: 00007f72f731ff59
[   62.049967][ T8152] RDX: ffffffffffffffff RSI: 0000000000001fd8 RDI: 000055dad0ac6c00
[   62.051954][ T8152] RBP: 000000000000012a R08: 0000000000000000 R09: 0000000037ecd53b
[   62.053953][ T8152] R10: ffffffffffffffff R11: 0000000000000246 R12: 0000000000000002
[   62.055966][ T8152] R13: 00007f72f5c7b058 R14: 00007f72f72086c0 R15: 00007f72f5c7b000
[   62.057961][ T8152]  </TASK>
[   62.058735][ T8152] ---[ end trace d948954eb385fb99 ]---
[   64.410009][ T2470] result_service: raw_upload, RESULT_MNT: /internal-lkp-server/result, RESULT_ROOT: /internal-lkp-server/result/trinity/group-03-300s/vm-snb/debian-10.4-x86_64-20200603.cgz/x86_64-kexec/gcc-9/f7cf7134e405062bf0f22c3ba5637241c4c4d06a/3, TMP_RESULT_ROOT: /tmp/lkp/result
[   64.410031][ T2470]
[   64.429418][ T2470] run-job /lkp/jobs/scheduled/vm-snb-123/trinity-group-03-300s-debian-10.4-x86_64-20200603.cgz-f7cf7134e405062bf0f22c3ba5637241c4c4d06a-20220115-27780-1ajh2ux-5.yaml
[   64.429432][ T2470]
[   66.886071][ T2470] /usr/bin/wget -q --timeout=1800 --tries=1 --local-encoding=UTF-8 http://internal-lkp-server:80/~lkp/cgi-bin/lkp-jobfile-append-var?job_file=/lkp/jobs/scheduled/vm-snb-123/trinity-group-03-300s-debian-10.4-x86_64-20200603.cgz-f7cf7134e405062bf0f22c3ba5637241c4c4d06a-20220115-27780-1ajh2ux-5.yaml&job_state=running -O /dev/null
[   66.886087][ T2470]
[   66.900236][ T2470] target ucode:
[   66.900245][ T2470]
[   66.907783][ T2470] Seeding trinity by 3185738815 based on vm-snb/debian-10.4-x86_64-20200603.cgz/x86_64-kexec
[   66.907811][ T2470]
[   75.752629][ T2470] 2022-01-15 08:08:38 chroot --userspec nobody:nogroup / trinity -q -q -l off -s 3185738815 -N 999999999 -c add_key -c bpf -c clock_adjtime -c clone3 -c copy_file_range -c creat -c epoll_create1 -c fadvise64_64 -c fchdir -c fdatasync -c geteuid16 -c getgroups -c gettimeofday -c inotify_init -c io_uring_register -c io_uring_setup -c ioctl -c kcmp -c keyctl -c lsetxattr -c lstat -c mkdirat -c mknod -c mknodat -c mmap2 -c mq_getsetattr -c munlockall -c olduname -c openat -c perf_event_open -c personality -c pidfd_open -c poll -c prctl -c preadv -c process_madvise -c process_mrelease -c ptrace -c quotactl -c readlinkat -c rt_sigtimedwait -c sched_getattr -c sched_rr_get_interval -c setgid -c setgroups -c setrlimit -c setsid -c signalfd4 -c statfs -c stime -c syncfs -c timer_create -c timer_delete -c timer_gettime -c timerfd_create -c uname -c utimensat -c vm86old -c vmsplice
[   75.752696][ T2470]
[   80.049523][ T2470] Trinity 2021.10  Dave Jones <davej@...emonkey.org.uk>
[   80.049600][ T2470]
[   80.056064][ T2470] shm:0x7f72f73f9000-0x7f7303ff5d00 (4 pages)
[   80.056078][ T2470]
[   81.317675][ T2470] [main] Marking syscall add_key (64bit:248 32bit:286) as to be enabled.
[   81.317695][ T2470]
[   81.326020][ T2470] [main] Marking syscall bpf (64bit:321 32bit:357) as to be enabled.
[   81.326033][ T2470]
[   81.762673][ T2470] [main] Marking syscall clock_adjtime (64bit:305 32bit:343) as to be enabled.
[   81.762703][ T2470]
[   81.769765][ T2470] [main] clone3 is marked as AVOID. Skipping
[   81.769779][ T2470]
[   81.775664][ T2470] [main] clone3 is marked as AVOID. Skipping
[   81.775679][ T2470]
[   81.783066][ T2470] [main] Marking syscall clone3 (64bit:435 32bit:428) as to be enabled.
[   81.783089][ T2470]
[   81.932838][ T2470] [main] Marking syscall copy_file_range (64bit:326 32bit:377) as to be enabled.
[   81.932853][ T2470]
[   81.941437][ T2470] [main] Marking syscall creat (64bit:85 32bit:8) as to be enabled.
[   81.941458][ T2470]
[   81.950070][ T2470] [main] Marking syscall epoll_create1 (64bit:291 32bit:329) as to be enabled.
[   81.950086][ T2470]
[   81.958583][ T2470] [main] Marking 32-bit syscall fadvise64_64 (272) as to be enabled.
[   81.958597][ T2470]
[   81.969906][ T2470] [main] Marking syscall fchdir (64bit:81 32bit:133) as to be enabled.
[   81.969924][ T2470]
[   81.978369][ T2470] [main] Marking syscall fdatasync (64bit:75 32bit:148) as to be enabled.
[   81.978384][ T2470]
[   81.986696][ T2470] [main] Marking 32-bit syscall geteuid16 (49) as to be enabled.
[   81.986711][ T2470]
[   81.995106][ T2470] [main] Marking syscall getgroups (64bit:115 32bit:205) as to be enabled.
[   81.995123][ T2470]
[   82.004068][ T2470] [main] Marking syscall gettimeofday (64bit:96 32bit:78) as to be enabled.
[   82.004084][ T2470]
[   82.013067][ T2470] [main] Marking syscall inotify_init (64bit:253 32bit:291) as to be enabled.
[   82.013081][ T2470]


To reproduce:

        # build kernel
	cd linux
	cp config-5.16.0-rc1-00018-gf7cf7134e405 .config
	make HOSTCC=gcc-9 CC=gcc-9 ARCH=x86_64 olddefconfig prepare modules_prepare bzImage modules
	make HOSTCC=gcc-9 CC=gcc-9 ARCH=x86_64 INSTALL_MOD_PATH=<mod-install-dir> modules_install
	cd <mod-install-dir>
	find lib/ | cpio -o -H newc --quiet | gzip > modules.cgz


        git clone https://github.com/intel/lkp-tests.git
        cd lkp-tests
        bin/lkp qemu -k <bzImage> -m modules.cgz job-script # job-script is attached in this email

        # if come across any failure that blocks the test,
        # please remove ~/.lkp and /lkp dir to run from a clean state.



---
0DAY/LKP+ Test Infrastructure                   Open Source Technology Center
https://lists.01.org/hyperkitty/list/lkp@lists.01.org       Intel Corporation

Thanks,
Oliver Sang


View attachment "config-5.16.0-rc1-00018-gf7cf7134e405" of type "text/plain" (122287 bytes)

View attachment "job-script" of type "text/plain" (4605 bytes)

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

View attachment "trinity" of type "text/plain" (11138 bytes)

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ