2020-12-25 14:25:43

by Qiujun Huang

[permalink] [raw]
Subject: [PATCH] trace: Remove get/put_cpu() from function_trace_init

Since commit b6f11df26fdc ("trace: Call tracing_reset_online_cpus before
tracer->init()"), get/put_cpu() are not needed anymore.
We can use smp_processor_id() instead.

Signed-off-by: Qiujun Huang <[email protected]>
---
kernel/trace/trace_functions.c | 3 +--
1 file changed, 1 insertion(+), 2 deletions(-)

diff --git a/kernel/trace/trace_functions.c b/kernel/trace/trace_functions.c
index c5095dd28e20..e36fbb935017 100644
--- a/kernel/trace/trace_functions.c
+++ b/kernel/trace/trace_functions.c
@@ -106,8 +106,7 @@ static int function_trace_init(struct trace_array *tr)

ftrace_init_array_ops(tr, func);

- tr->array_buffer.cpu = get_cpu();
- put_cpu();
+ tr->array_buffer.cpu = smp_processor_id();

tracing_start_cmdline_record();
tracing_start_function_trace(tr);
--
2.17.1


2020-12-30 07:36:22

by Oliver Sang

[permalink] [raw]
Subject: [trace] 2158a32526: BUG:using_smp_processor_id()in_preemptible


Greeting,

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

commit: 2158a32526b660c34eedc2eaef2bbd623227dd84 ("[PATCH] trace: Remove get/put_cpu() from function_trace_init")
url: https://github.com/0day-ci/linux/commits/Qiujun-Huang/trace-Remove-get-put_cpu-from-function_trace_init/20201225-222645
base: https://git.kernel.org/cgit/linux/kernel/git/tip/tip.git c2208046bba6842dc232a600dc5cafc2fca41078

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

group: group-01
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: 8 threads Intel(R) Core(TM) i7-6770HQ CPU @ 2.60GHz 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 <[email protected]>


kern :err : [ 89.914811] BUG: using smp_processor_id() in preemptible [00000000] code: ftracetest/10346
kern :warn : [ 89.923315] caller is function_trace_init+0x3d/0x80
kern :warn : [ 89.928379] CPU: 6 PID: 10346 Comm: ftracetest Tainted: G I 5.10.0-rc5-00048-g2158a32526b6 #1
kern :warn : [ 89.938618] Hardware name: /NUC6i7KYB, BIOS KYSKLi70.86A.0041.2016.0817.1130 08/17/2016
kern :warn : [ 89.947067] Call Trace:
kern :warn : [ 89.949611] dump_stack+0x8d/0xb5
kern :warn : [ 89.953090] check_preemption_disabled+0xc3/0xe0
kern :warn : [ 89.957991] function_trace_init+0x3d/0x80
kern :warn : [ 89.962284] tracing_set_tracer+0x138/0x220
kern :warn : [ 89.966620] tracing_set_trace_write+0x95/0xe0
kern :warn : [ 89.971222] ? ksys_write+0x68/0xe0
kern :warn : [ 89.974839] vfs_write+0xee/0x3c0
kern :warn : [ 89.978288] ksys_write+0x68/0xe0
kern :warn : [ 89.981707] do_syscall_64+0x33/0x40
kern :warn : [ 89.985450] entry_SYSCALL_64_after_hwframe+0x44/0xa9
user :notice: [ 89.988062] # Check success of execveat(5, '../execveat', 0)... [OK]
kern :warn : [ 89.990669] RIP: 0033:0x7f7d1f648504
kern :warn : [ 89.990678] Code: 00 f7 d8 64 89 02 48 c7 c0 ff ff ff ff eb b3 0f 1f 80 00 00 00 00 48 8d 05 f9 61 0d 00 8b 00 85 c0 75 13 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 54 c3 0f 1f 00 41 54 49 89 d4 55 48 89 f5 53

kern :warn : [ 90.000988] RSP: 002b:00007fff326418a8 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
kern :warn : [ 90.000990] RAX: ffffffffffffffda RBX: 0000000000000009 RCX: 00007f7d1f648504
kern :warn : [ 90.000991] RDX: 0000000000000009 RSI: 0000563de1bc3920 RDI: 0000000000000001
kern :warn : [ 90.000992] RBP: 0000563de1bc3920 R08: 000000000000000a R09: 00007f7d1f6d8e80
kern :warn : [ 90.000994] R10: 000000000000000a R11: 0000000000000246 R12: 00007f7d1f71a760
kern :warn : [ 90.000995] R13: 0000000000000009 R14: 00007f7d1f715760 R15: 0000000000000009
user :notice: [ 90.068488] # Check success of execveat(7, 'execveat', 0)... [OK]

user :notice: [ 90.077748] # Check success of execveat(9, 'execveat', 0)... [OK]

user :notice: [ 91.944852] # Check success of execveat(-100, '/usr/src/perf_selfte...ftests/exec/execveat', 0)... [OK]

user :notice: [ 91.958685] # Check success of execveat(99, '/usr/src/perf_selfte...ftests/exec/execveat', 0)... [OK]

user :notice: [ 91.971263] # Check success of execveat(11, '', 4096)... [OK]

user :notice: [ 91.980178] # Check success of execveat(20, '', 4096)... [OK]

user :notice: [ 91.989100] # Check success of execveat(12, '', 4096)... [OK]

user :notice: [ 91.998064] # Check success of execveat(17, '', 4096)... [OK]

user :notice: [ 92.007057] # Check success of execveat(17, '', 4096)... [OK]

user :notice: [ 92.016034] # Check success of execveat(18, '', 4096)... [OK]

user :notice: [ 92.025178] # Check failure of execveat(11, '', 0) with ENOENT... [OK]

user :notice: [ 92.035300] # Check failure of execveat(11, '(null)', 4096) with EFAULT... [OK]

user :notice: [ 92.046380] # Check success of execveat(7, 'execveat.symlink', 0)... [OK]

user :notice: [ 92.056637] # Check success of execveat(9, 'execveat.symlink', 0)... [OK]

user :notice: [ 92.067857] # Check success of execveat(-100, '/usr/src/perf_selfte...xec/execveat.symlink', 0)... [OK]

user :notice: [ 92.080671] # Check success of execveat(13, '', 4096)... [OK]

user :notice: [ 92.090051] # Check success of execveat(13, '', 4352)... [OK]

user :notice: [ 92.100312] # Check failure of execveat(7, 'execveat.symlink', 256) with ELOOP... [OK]

user :notice: [ 92.112462] # Check failure of execveat(9, 'execveat.symlink', 256) with ELOOP... [OK]


kern :warn : [ 93.511413] **********************************************************
kern :warn : [ 93.518345] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE **
kern :warn : [ 93.525104] ** **
kern :warn : [ 93.531889] ** trace_printk() being used. Allocating extra memory. **
kern :warn : [ 93.538660] ** **
kern :warn : [ 93.545394] ** This means that this is a DEBUG kernel and it is **
kern :warn : [ 93.552308] ** unsafe for production use. **
kern :warn : [ 93.559159] ** **
kern :warn : [ 93.566088] ** If you see this message and you are not debugging **
kern :warn : [ 93.572951] ** the kernel, report this immediately to your vendor! **
kern :warn : [ 93.579780] ** **
kern :warn : [ 93.586630] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE **
kern :warn : [ 93.593501] **********************************************************
user :notice: [ 96.683973] # Check failure of execveat(-100, '/usr/src/perf_selftests-x86_64-rhel-7.6-kselftests-2158a32526b660c34eedc2eaef2bbd623227dd84/tools/testing/selftests/exec/execveat.symlink', 256) with ELOOP... [OK]

user :notice: [ 96.706608] # Check failure of execveat(7, 'pipe', 0) with EACCES... [OK]

user :notice: [ 96.716823] # Check success of execveat(5, '../script', 0)... [OK]

user :notice: [ 96.726318] # Check success of execveat(7, 'script', 0)... [OK]

user :notice: [ 96.735349] # Check success of execveat(9, 'script', 0)... [OK]

user :notice: [ 96.745231] # Check success of execveat(-100, '/usr/src/perf_selfte...elftests/exec/script', 0)... [OK]

user :notice: [ 96.757894] # Check success of execveat(16, '', 4096)... [OK]

user :notice: [ 96.766599] # Check success of execveat(16, '', 4352)... [OK]

user :notice: [ 96.775638] # Check failure of execveat(21, '', 4096) with ENOENT... [OK]

user :notice: [ 96.785800] # Check failure of execveat(10, 'script', 0) with ENOENT... [OK]

user :notice: [ 96.795985] # Check success of execveat(19, '', 4096)... [OK]

user :notice: [ 96.804779] # Check success of execveat(19, '', 4096)... [OK]



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


Attachments:
(No filename) (7.43 kB)
config-5.10.0-rc5-00048-g2158a32526b6 (214.12 kB)
job-script (7.11 kB)
kmsg.xz (83.79 kB)
kernel-selftests (158.78 kB)
job.yaml (6.15 kB)
reproduce (717.00 B)
Download all attachments

2020-12-30 13:33:26

by Qiujun Huang

[permalink] [raw]
Subject: Re: [PATCH] trace: Remove get/put_cpu() from function_trace_init

Sorry, please ignore the patch

[trace] 2158a32526: BUG:using_smp_processor_id()in_preemptible

Thanks

On Fri, Dec 25, 2020 at 10:24 PM Qiujun Huang <[email protected]> wrote:
>
> Since commit b6f11df26fdc ("trace: Call tracing_reset_online_cpus before
> tracer->init()"), get/put_cpu() are not needed anymore.
> We can use smp_processor_id() instead.
>
> Signed-off-by: Qiujun Huang <[email protected]>
> ---
> kernel/trace/trace_functions.c | 3 +--
> 1 file changed, 1 insertion(+), 2 deletions(-)
>
> diff --git a/kernel/trace/trace_functions.c b/kernel/trace/trace_functions.c
> index c5095dd28e20..e36fbb935017 100644
> --- a/kernel/trace/trace_functions.c
> +++ b/kernel/trace/trace_functions.c
> @@ -106,8 +106,7 @@ static int function_trace_init(struct trace_array *tr)
>
> ftrace_init_array_ops(tr, func);
>
> - tr->array_buffer.cpu = get_cpu();
> - put_cpu();
> + tr->array_buffer.cpu = smp_processor_id();
>
> tracing_start_cmdline_record();
> tracing_start_function_trace(tr);
> --
> 2.17.1
>