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]
Date:   Tue, 24 Nov 2020 13:02:49 +0800
From:   kernel test robot <oliver.sang@...el.com>
To:     Marcelo Tosatti <mtosatti@...hat.com>
Cc:     0day robot <lkp@...el.com>, Christoph Lameter <cl@...ux.com>,
        LKML <linux-kernel@...r.kernel.org>, lkp@...ts.01.org,
        linux-mm@...ck.org, Andrew Morton <akpm@...ux-foundation.org>
Subject: [mm]  e655d17ffa: BUG:using_smp_processor_id()in_preemptible


Greeting,

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

commit: e655d17ffada57d11a82336a43fd91dd9c2ecbd2 ("[PATCH] mm: introduce sysctl file to flush per-cpu vmstat statistics")
url: https://github.com/0day-ci/linux/commits/Marcelo-Tosatti/mm-introduce-sysctl-file-to-flush-per-cpu-vmstat-statistics/20201118-002950
base: https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git 9c87c9f41245baa3fc4716cf39141439cf405b01

in testcase: kernel-selftests
version: kernel-selftests-x86_64-b5a583fb-1_20201015
with following parameters:

	group: group-02
	ucode: 0xe2

test-description: The kernel contains a set of "self tests" under the tools/testing/selftests/ directory. These are intended to be small unit tests to exercise individual code paths in the kernel.
test-url: https://www.kernel.org/doc/Documentation/kselftest.txt


on test machine: 4 threads Intel(R) Core(TM) i5-6500 CPU @ 3.20GHz with 32G memory

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


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


kern  :err   : [  318.711546] BUG: using smp_processor_id() in preemptible [00000000] code: read/27945
kern  :warn  : [  318.719301] caller is proc_quiet_vmstat+0x44/0x80
kern  :warn  : [  318.724037] CPU: 1 PID: 27945 Comm: read Not tainted 5.10.0-rc4-00068-ge655d17ffada #1
kern  :warn  : [  318.731971] Hardware name: Dell Inc. OptiPlex 7040/0Y7WYT, BIOS 1.8.1 12/05/2017
kern  :warn  : [  318.739377] Call Trace:
kern  :warn  : [  318.741824]  dump_stack+0x8d/0xb5
kern  :warn  : [  318.745140]  check_preemption_disabled+0xc3/0xe0
kern  :warn  : [  318.749761]  proc_quiet_vmstat+0x44/0x80
kern  :warn  : [  318.753684]  __cgroup_bpf_run_filter_sysctl+0xa4/0x580
kern  :warn  : [  318.758834]  proc_sys_call_handler+0x20f/0x260
kern  :warn  : [  318.763282]  new_sync_read+0x11b/0x1a0
kern  :warn  : [  318.767039]  vfs_read+0x16d/0x1e0
kern  :warn  : [  318.770381]  ksys_read+0x68/0xe0
kern  :warn  : [  318.773612]  do_syscall_64+0x33/0x40
kern  :warn  : [  318.777188]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
kern  :warn  : [  318.782241] RIP: 0033:0x7fe113db4461
kern  :warn  : [  318.785816] Code: fe ff ff 50 48 8d 3d fe d0 09 00 e8 e9 03 02 00 66 0f 1f 84 00 00 00 00 00 48 8d 05 99 62 0d 00 8b 00 85 c0 75 13 31 c0 0f 05 <48> 3d 00 f0 ff ff 77 57 c3 66 0f 1f 44 00 00 41 54 49 89 d4 55 48
kern  :warn  : [  318.804587] RSP: 002b:00007ffdfe04a328 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
kern  :warn  : [  318.812158] RAX: ffffffffffffffda RBX: 0000000000000008 RCX: 00007fe113db4461
kern  :warn  : [  318.819293] RDX: 0000000000001000 RSI: 00007ffdfe04a330 RDI: 0000000000000008
kern  :warn  : [  318.826430] RBP: 0000559d31881039 R08: 0000000000000003 R09: 0000000000000078
kern  :warn  : [  318.833565] R10: 0000000000000000 R11: 0000000000000246 R12: 0000559d31881038
kern  :warn  : [  318.840704] R13: 0000000000000002 R14: 0000559d3188107a R15: 0000559d32a6f9db
kern  :err   : [  318.847944] BUG: using smp_processor_id() in preemptible [00000000] code: read/27945
kern  :warn  : [  318.855728] caller is proc_quiet_vmstat+0x44/0x80
kern  :warn  : [  318.860612] CPU: 1 PID: 27945 Comm: read Not tainted 5.10.0-rc4-00068-ge655d17ffada #1
kern  :warn  : [  318.868542] Hardware name: Dell Inc. OptiPlex 7040/0Y7WYT, BIOS 1.8.1 12/05/2017
kern  :warn  : [  318.875938] Call Trace:
kern  :warn  : [  318.878387]  dump_stack+0x8d/0xb5
kern  :warn  : [  318.881706]  check_preemption_disabled+0xc3/0xe0
kern  :warn  : [  318.886341]  proc_quiet_vmstat+0x44/0x80
kern  :warn  : [  318.890278]  proc_sys_call_handler+0x13e/0x260
kern  :warn  : [  318.894728]  new_sync_read+0x11b/0x1a0
kern  :warn  : [  318.898486]  vfs_read+0x16d/0x1e0
kern  :warn  : [  318.901804]  ksys_read+0x68/0xe0
kern  :warn  : [  318.905035]  do_syscall_64+0x33/0x40
kern  :warn  : [  318.908612]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
kern  :warn  : [  318.913662] RIP: 0033:0x7fe113db4461
kern  :warn  : [  318.917237] Code: fe ff ff 50 48 8d 3d fe d0 09 00 e8 e9 03 02 00 66 0f 1f 84 00 00 00 00 00 48 8d 05 99 62 0d 00 8b 00 85 c0 75 13 31 c0 0f 05 <48> 3d 00 f0 ff ff 77 57 c3 66 0f 1f 44 00 00 41 54 49 89 d4 55 48
kern  :warn  : [  318.936009] RSP: 002b:00007ffdfe04a328 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
kern  :warn  : [  318.943578] RAX: ffffffffffffffda RBX: 0000000000000008 RCX: 00007fe113db4461
kern  :warn  : [  318.950715] RDX: 0000000000001000 RSI: 00007ffdfe04a330 RDI: 0000000000000008
kern  :warn  : [  318.957849] RBP: 0000559d31881039 R08: 0000000000000003 R09: 0000000000000078
kern  :warn  : [  318.964982] R10: 0000000000000000 R11: 0000000000000246 R12: 0000559d31881038
kern  :warn  : [  318.972116] R13: 0000000000000002 R14: 0000559d3188107a R15: 0000559d32a6f9db
kern  :info  : [  319.061697] sysrq: HELP : loglevel(0-9) reboot(b) crash(c) show-all-locks(d) terminate-all-tasks(e) memory-full-oom-kill(f) kill-all-tasks(i) thaw-filesystems(j) sak(k) show-backtrace-all-active-cpus(l) show-memory-usage(m) nice-all-RT-tasks(n) poweroff(o) show-registers(p) show-all-timers(q) unraw(r) sync(s) show-task-states(t) unmount(u) show-blocked-tasks(w) dump-ftrace-buffer(z) 
user  :notice: [  321.570463] ok 12 selftests: proc: read

user  :notice: [  321.577830] # selftests: proc: self

user  :notice: [  321.599985] ok 13 selftests: proc: self

user  :notice: [  321.606065] # selftests: proc: setns-dcache

user  :notice: [  321.627516] ok 14 selftests: proc: setns-dcache

user  :notice: [  321.634335] # selftests: proc: setns-sysvipc

user  :notice: [  321.655104] ok 15 selftests: proc: setns-sysvipc

user  :notice: [  321.662039] # selftests: proc: thread-self

user  :notice: [  321.682210] ok 16 selftests: proc: thread-self

user  :notice: [  321.689137] # selftests: proc: proc-multiple-procfs

user  :notice: [  321.710024] ok 17 selftests: proc: proc-multiple-procfs

user  :notice: [  321.717763] # selftests: proc: proc-fsconfig-hidepid

user  :notice: [  321.737068] ok 18 selftests: proc: proc-fsconfig-hidepid

user  :notice: [  321.745566] make: warning:  Clock skew detected.  Your build may be incomplete.

user  :notice: [  321.757738] make: Leaving directory '/usr/src/perf_selftests-x86_64-rhel-7.6-kselftests-e655d17ffada57d11a82336a43fd91dd9c2ecbd2/tools/testing/selftests/proc'

kern  :info  : [  321.792514] ramoops: using module parameters
kern  :info  : [  321.798332] pstore: Using crash dump compression: deflate
kern  :info  : [  321.804336] printk: console [ramoops-1] enabled
kern  :info  : [  321.809491] pstore: Registered ramoops as persistent store backend
kern  :info  : [  321.815684] ramoops: using 0xf4240@...000000, ecc: 0
user  :notice: [  321.827756] 2019-02-14 10:16:47 make run_tests -C pstore

user  :notice: [  321.857425] make: Entering directory '/usr/src/perf_selftests-x86_64-rhel-7.6-kselftests-e655d17ffada57d11a82336a43fd91dd9c2ecbd2/tools/testing/selftests/pstore'

user  :notice: [  321.875269] make: Warning: File '../lib.mk' has modification time 55836578 s in the future

user  :notice: [  321.885765] TAP version 13

user  :notice: [  321.890482] 1..2

user  :notice: [  321.894762] # selftests: pstore: pstore_tests

user  :notice: [  321.903480] # === Pstore unit tests (pstore_tests) ===

user  :notice: [  321.911204] # UUID=a6a480bd-f511-418e-83f0-0c625840f032

user  :notice: [  321.919011] # Checking pstore backend is registered ... ok

user  :notice: [  321.926522] # 	backend=ramoops

user  :notice: [  325.968623] # 	cmdline=ip=::::lkp-skl-d05::dhcp root=/dev/ram0 user=lkp job=/lkp/jobs/scheduled/lkp-skl-d05/kernel-selftests-group-02-ucode=0xe2-debian-10.4-x86_64-20200603.cgz-e655d17ffada57d11a82336a43fd91dd9c2ecbd2-20201122-19793-14arzjn-2.yaml ARCH=x86_64 kconfig=x86_64-rhel-7.6-kselftests branch=linux-review/Marcelo-Tosatti/mm-introduce-sysctl-file-to-flush-per-cpu-vmstat-statistics/20201118-002950 commit=e655d17ffada57d11a82336a43fd91dd9c2ecbd2 BOOT_IMAGE=/pkg/linux/x86_64-rhel-7.6-kselftests/gcc-9/e655d17ffada57d11a82336a43fd91dd9c2ecbd2/vmlinuz-5.10.0-rc4-00068-ge655d17ffada erst_disable max_uptime=3600 RESULT_ROOT=/result/kernel-selftests/group-02-ucode=0xe2/lkp-skl-d05/debian-10.4-x86_64-20200603.cgz/x86_64-rhel-7.6-kselftests/gcc-9/e655d17ffada57d11a82336a43fd91dd9c2ecbd2/3 LKP_SERVER=internal-lkp-server nokaslr selinux=0 debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeou

user  :notice: [  328.399180] # Checking pstore console is registered ... ok

user  :notice: [  328.406998] # Checking /dev/pmsg0 exists ... ok

user  :notice: [  328.414030] # Writing unique string to /dev/pmsg0 ... ok

user  :notice: [  328.421763] ok 1 selftests: pstore: pstore_tests

user  :notice: [  328.428885] # selftests: pstore: pstore_post_reboot_tests

user  :notice: [  328.818409] # === Pstore unit tests (pstore_post_reboot_tests) ===

user  :notice: [  328.827075] # UUID=5d84a735-2106-4f87-b7dd-61334ca4ce96

user  :notice: [  328.834896] # Checking pstore backend is registered ... ok

user  :notice: [  328.842335] # 	backend=ramoops

user  :notice: [  341.500511] # 	cmdline=ip=::::lkp-skl-d05::dhcp root=/dev/ram0 user=lkp job=/lkp/jobs/scheduled/lkp-skl-d05/kernel-selftests-group-02-ucode=0xe2-debian-10.4-x86_64-20200603.cgz-e655d17ffada57d11a82336a43fd91dd9c2ecbd2-20201122-19793-14arzjn-2.yaml ARCH=x86_64 kconfig=x86_64-rhel-7.6-kselftests branch=linux-review/Marcelo-Tosatti/mm-introduce-sysctl-file-to-flush-per-cpu-vmstat-statistics/20201118-002950 commit=e655d17ffada57d11a82336a43fd91dd9c2ecbd2 BOOT_IMAGE=/pkg/linux/x86_64-rhel-7.6-kselftests/gcc-9/e655d17ffada57d11a82336a43fd91dd9c2ecbd2/vmlinuz-5.10.0-rc4-00068-ge655d17ffada erst_disable max_uptime=3600 RESULT_ROOT=/result/kernel-selftests/group-02-ucode=0xe2/lkp-skl-d05/debian-10.4-x86_64-20200603.cgz/x86_64-rhel-7.6-kselftests/gcc-9/e655d17ffada57d11a82336a43fd91dd9c2ecbd2/3 LKP_SERVER=internal-lkp-server nokaslr selinux=0 debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeou

user  :notice: [  345.010149] # pstore_crash_test has not been executed yet. we skip further tests.


To reproduce:

        git clone https://github.com/intel/lkp-tests.git
        cd lkp-tests
        bin/lkp install job.yaml  # job file is attached in this email
        bin/lkp run     job.yaml



Thanks,
Oliver Sang


View attachment "config-5.10.0-rc4-00068-ge655d17ffada" of type "text/plain" (209900 bytes)

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

Download attachment "kmsg.xz" of type "application/x-xz" (58968 bytes)

View attachment "kernel-selftests" of type "text/plain" (223372 bytes)

View attachment "job.yaml" of type "text/plain" (6154 bytes)

View attachment "reproduce" of type "text/plain" (1060 bytes)

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ