* [PATCH] perf/core: Fix to check perf_cpu_time_max_percent
@ 2017-02-23 6:04 Tan Xiaojun
2017-02-24 9:15 ` [tip:perf/urgent] perf/core: Fix the perf_cpu_time_max_percent check tip-bot for Tan Xiaojun
0 siblings, 1 reply; 18+ messages in thread
From: Tan Xiaojun @ 2017-02-23 6:04 UTC (permalink / raw)
To: peterz, mingo, acme, alexander.shishkin; +Cc: linux-kernel
Use "proc_dointvec_minmax" instead of "proc_dointvec" to check the input
value from userspace.
If not, we can set a big value and some vars will overflow like
"sysctl_perf_event_sample_rate". And it will cause a lot of unexpected
problems.
When I found this problem, I was doing the perf_fuzzer test in Hisilicon
D03. And get logs below(from console):
**********************************************************
[ 90.880860] perf: Dynamic interrupt throttling disabled, can hang your system!
[ 90.896873] perf: Dynamic interrupt throttling disabled, can hang your system!
[ 91.884088] perf: Dynamic interrupt throttling disabled, can hang your system!
[ 96.466762] perf: interrupt took too long (46 > 1), lowering kernel.perf_event_max_sample_rate to 175250
[ 96.476228] perf: interrupt took too long (68 > 57), lowering kernel.perf_event_max_sample_rate to 117500
[ 96.485774] perf: interrupt took too long (97 > 85), lowering kernel.perf_event_max_sample_rate to 82500
[ 96.495249] perf: interrupt took too long (145 > 121), lowering kernel.perf_event_max_sample_rate to 55000
[ 96.737083] perf: interrupt took too long (194 > 181), lowering kernel.perf_event_max_sample_rate to 41250
[ 96.762287] perf: interrupt took too long (281 > 242), lowering kernel.perf_event_max_sample_rate to 28250
[ 96.784693] perf: interrupt took too long (369 > 351), lowering kernel.perf_event_max_sample_rate to 21500
[ 98.094492] perf: Dynamic interrupt throttling disabled, can hang your system!
[ 99.550597] perf: interrupt took too long (10 > 1), lowering kernel.perf_event_max_sample_rate to -383141598
[ 99.576690] perf: interrupt took too long (15 > 12), lowering kernel.perf_event_max_sample_rate to -1687083664
[ 99.602955] perf: interrupt took too long (21 > 18), lowering kernel.perf_event_max_sample_rate to -176834776
[ 99.629749] perf: interrupt took too long (32 > 26), lowering kernel.perf_event_max_sample_rate to -544439184
[ 99.656491] perf: interrupt took too long (48 > 40), lowering kernel.perf_event_max_sample_rate to -1794615388
[ 99.689272] perf: interrupt took too long (66 > 60), lowering kernel.perf_event_max_sample_rate to -475090842
[ 101.823705] perf: interrupt took too long (1932 > 1), lowering kernel.perf_event_max_sample_rate to 8250
[ 102.368030] perf: Dynamic interrupt throttling disabled, can hang your system!
[ 105.872880] perf: Dynamic interrupt throttling disabled, can hang your system!
[ 138.222411] perf: interrupt took too long (449 > 1), lowering kernel.perf_event_max_sample_rate to 1858059000
[ 159.219465] INFO: rcu_preempt self-detected stall on CPU
[ 159.224774] 8-...: (4 GPs behind) idle=dab/140000000000002/0 softirq=18839/18840 fqs=2625
[ 159.227465] INFO: rcu_preempt detected stalls on CPUs/tasks:
[ 159.227470] 8-...: (4 GPs behind) idle=dab/140000000000002/0 softirq=18839/18840 fqs=2625
[ 159.227471] (detected by 5, t=5252 jiffies, g=7249, c=7248, q=314)
[ 159.227476] Task dump for CPU 8:
[ 159.227477] perf_fuzzer R running task 0 11327 4975 0x00000203
[ 159.227481] Call trace:
[ 159.227487] [<ffff000008082eb0>] ret_from_fork+0x0/0x50
[ 159.271265] (t=5262 jiffies g=7249 c=7248 q=314)
[ 159.276055] Task dump for CPU 8:
[ 159.279283] perf_fuzzer R running task 0 11327 4975 0x00000203
[ 159.286317] Call trace:
[ 159.288773] [<ffff0000080883d4>] dump_backtrace+0x0/0x240
[ 159.294167] [<ffff000008088628>] show_stack+0x14/0x1c
[ 159.299215] [<ffff0000080e5f84>] sched_show_task+0x130/0x174
[ 159.304866] [<ffff0000080e8948>] dump_cpu_task+0x40/0x4c
[ 159.310171] [<ffff00000816f944>] rcu_dump_cpu_stacks+0xa4/0xec
[ 159.315996] [<ffff00000811a160>] rcu_check_callbacks+0x9d8/0xc70
[ 159.321992] [<ffff00000811e0e8>] update_process_times+0x2c/0x58
[ 159.327893] [<ffff00000812d1cc>] tick_sched_handle.isra.17+0x20/0x60
[ 159.334234] [<ffff00000812d250>] tick_sched_timer+0x44/0x88
[ 159.339799] [<ffff00000811e980>] __hrtimer_run_queues+0xe8/0x14c
[ 159.345795] [<ffff00000811ef04>] hrtimer_interrupt+0x9c/0x1e0
[ 159.351536] [<ffff000008793a94>] arch_timer_handler_virt+0x2c/0x38
[ 159.357708] [<ffff00000810f554>] handle_percpu_devid_irq+0x78/0x12c
[ 159.363967] [<ffff00000810a5ec>] generic_handle_irq+0x24/0x38
[ 159.369705] [<ffff00000810ac84>] __handle_domain_irq+0x60/0xac
[ 159.375526] [<ffff0000080816e4>] gic_handle_irq+0x74/0x174
[ 159.381003] Exception stack(0xffff803ffff34df0 to 0xffff803ffff34f20)
[ 159.387429] 4de0: ffff803ffff34e20 0001000000000000
[ 159.395241] 4e00: ffff803ffff34f50 ffff0000080c29b0 0000000040000145 000000000000001b
[ 159.403052] 4e20: 0000000000000400 ffff000008ed3300 ffff000008ed3300 0000803ff7196000
[ 159.410864] 4e40: 000000000ccccccd 0000000000000020 000dc56c20000000 0000000000000032
[ 159.418676] 4e60: 000000000000002e 000000003b9aca00 000000000000000d 656b20676e697265
[ 159.426487] 4e80: 7265702e6c656e72 5f746e6576655f66 ffff000008ba6000 0000803ff7196000
[ 159.434299] 4ea0: 000000000042c778 0000000000001c51 0000fffff3b48c50 ffff000008d9b000
[ 159.442111] 4ec0: 0000000000000000 ffff000008d9fb08 ffff000008d9b000 ffff000008bc5728
[ 159.449923] 4ee0: 000000000000001b ffff000008ba1000 ffff803ffff35090 0000000000000202
[ 159.457734] 4f00: ffff803f6efbe400 ffff803ffff34f50 ffff0000080c2e40 ffff803ffff34f50
[ 159.465550] [<ffff0000080827f4>] el1_irq+0xb4/0x128
[ 159.470422] [<ffff0000080c2e40>] irq_exit+0xd0/0x118
[ 159.475382] [<ffff00000810ac88>] __handle_domain_irq+0x64/0xac
[ 159.481205] [<ffff0000080816e4>] gic_handle_irq+0x74/0x174
[ 159.486684] Exception stack(0xffff803f70bfbec0 to 0xffff803f70bfbff0)
[ 159.493115] bec0: 000000000000136f 0000000000000000 0000000000014f4b 0000ffff8233c5f0
[ 159.500927] bee0: 0000ffff8233b270 0000000000000000 0000ffff823636f0 0000000000000000
[ 159.508740] bf00: 00000000000000ad 00000000ffffff80 0000000000000001 0000fffff3b48e10
[ 159.516552] bf20: 0000000000000000 0000000100000000 0000000000000000 00004a51a0000000
[ 159.524365] bf40: 000000000042c778 0000ffff82266c70 0000fffff3b48c50 0000000000414bd0
[ 159.532176] bf60: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
[ 159.539988] bf80: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
[ 159.547799] bfa0: 0000000000000000 0000fffff3b48e60 0000000000409264 0000fffff3b48e60
[ 159.555614] bfc0: 0000000000410a14 0000000020000000 0000000000000000 ffffffffffffffff
[ 159.563425] bfe0: 0000000000000000 0000000000000000
[ 159.568296] [<ffff000008082d18>] el0_irq_naked+0x4c/0x54
[ 185.429581] NMI watchdog: BUG: soft lockup - CPU#8 stuck for 22s! [perf_fuzzer:11327]
[ 185.437397] Modules linked in:
[ 185.440454]
[ 185.441956] CPU: 8 PID: 11327 Comm: perf_fuzzer Not tainted 4.10.0-rc1-ga1d2732-dirty #5
[ 185.450028] Hardware name: Huawei Taishan 2180 /BC11SPCC, BIOS 1.31 06/23/2016
[ 185.457235] task: ffff803f6efbe400 task.stack: ffff803f70bf8000
[ 185.463149] PC is at __do_softirq+0xc0/0x240
[ 185.467416] LR is at irq_exit+0xd0/0x118
[ 185.471340] pc : [<ffff0000080c29b0>] lr : [<ffff0000080c2e40>] pstate: 40000145
[ 185.478719] sp : ffff803ffff34f50
[ 185.482033] x29: ffff803ffff34f50 x28: ffff803f6efbe400
[ 185.487339] x27: 0000000000000202 x26: ffff803ffff35090
[ 185.492646] x25: ffff000008ba1000 x24: 000000000000001b
[ 185.497952] x23: ffff000008bc5728 x22: ffff000008d9b000
[ 185.503259] x21: ffff000008d9fb08 x20: 0000000000000000
[ 185.508566] x19: ffff000008d9b000 x18: 0000fffff3b48c50
[ 185.513872] x17: 0000000000001c51 x16: 000000000042c778
[ 185.519180] x15: 0000803ff7196000 x14: ffff000008ba6000
[ 185.524483] x13: 5f746e6576655f66 x12: 7265702e6c656e72
[ 185.529790] x11: 656b20676e697265 x10: 000000000000000d
[ 185.535093] x9 : 000000003b9aca00 x8 : 000000000000002e
[ 185.540400] x7 : 0000000000000032 x6 : 000dc56c20000000
[ 185.545707] x5 : 0000000000000020 x4 : 000000000ccccccd
[ 185.551010] x3 : 0000803ff7196000 x2 : ffff000008ed3300
[ 185.556313] x1 : ffff000008ed3300 x0 : 0000000000000400
[ 185.561619]
**********************************************************
Signed-off-by: Tan Xiaojun <tanxiaojun@huawei.com>
---
kernel/events/core.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/kernel/events/core.c b/kernel/events/core.c
index 77a932b..53b1747 100644
--- a/kernel/events/core.c
+++ b/kernel/events/core.c
@@ -455,7 +455,7 @@ int perf_cpu_time_max_percent_handler(struct ctl_table *table, int write,
void __user *buffer, size_t *lenp,
loff_t *ppos)
{
- int ret = proc_dointvec(table, write, buffer, lenp, ppos);
+ int ret = proc_dointvec_minmax(table, write, buffer, lenp, ppos);
if (ret || !write)
return ret;
--
1.9.1
^ permalink raw reply related [flat|nested] 18+ messages in thread
* [tip:perf/urgent] perf/core: Fix the perf_cpu_time_max_percent check
2017-02-23 6:04 [PATCH] perf/core: Fix to check perf_cpu_time_max_percent Tan Xiaojun
@ 2017-02-24 9:15 ` tip-bot for Tan Xiaojun
2017-02-25 8:10 ` Tan Xiaojun
0 siblings, 1 reply; 18+ messages in thread
From: tip-bot for Tan Xiaojun @ 2017-02-24 9:15 UTC (permalink / raw)
To: linux-tip-commits
Cc: tanxiaojun, acme, peterz, torvalds, tglx, vincent.weaver,
eranian, linux-kernel, acme, hpa, mingo, jolsa,
alexander.shishkin
Commit-ID: 1572e45a924f254d9570093abde46430c3172e3d
Gitweb: http://git.kernel.org/tip/1572e45a924f254d9570093abde46430c3172e3d
Author: Tan Xiaojun <tanxiaojun@huawei.com>
AuthorDate: Thu, 23 Feb 2017 14:04:39 +0800
Committer: Ingo Molnar <mingo@kernel.org>
CommitDate: Fri, 24 Feb 2017 08:56:33 +0100
perf/core: Fix the perf_cpu_time_max_percent check
Use "proc_dointvec_minmax" instead of "proc_dointvec" to check the input
value from user-space.
If not, we can set a big value and some vars will overflow like
"sysctl_perf_event_sample_rate" which will cause a lot of unexpected
problems.
Signed-off-by: Tan Xiaojun <tanxiaojun@huawei.com>
Signed-off-by: Peter Zijlstra (Intel) <peterz@infradead.org>
Cc: <acme@kernel.org>
Cc: <alexander.shishkin@linux.intel.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Linus Torvalds <torvalds@linux-foundation.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Cc: Thomas Gleixner <tglx@linutronix.de>
Cc: Vince Weaver <vincent.weaver@maine.edu>
Link: http://lkml.kernel.org/r/1487829879-56237-1-git-send-email-tanxiaojun@huawei.com
Signed-off-by: Ingo Molnar <mingo@kernel.org>
---
kernel/events/core.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/kernel/events/core.c b/kernel/events/core.c
index d4e3f8d..c1c1cdf 100644
--- a/kernel/events/core.c
+++ b/kernel/events/core.c
@@ -455,7 +455,7 @@ int perf_cpu_time_max_percent_handler(struct ctl_table *table, int write,
void __user *buffer, size_t *lenp,
loff_t *ppos)
{
- int ret = proc_dointvec(table, write, buffer, lenp, ppos);
+ int ret = proc_dointvec_minmax(table, write, buffer, lenp, ppos);
if (ret || !write)
return ret;
^ permalink raw reply related [flat|nested] 18+ messages in thread
* Re: [tip:perf/urgent] perf/core: Fix the perf_cpu_time_max_percent check
2017-02-24 9:15 ` [tip:perf/urgent] perf/core: Fix the perf_cpu_time_max_percent check tip-bot for Tan Xiaojun
@ 2017-02-25 8:10 ` Tan Xiaojun
0 siblings, 0 replies; 18+ messages in thread
From: Tan Xiaojun @ 2017-02-25 8:10 UTC (permalink / raw)
To: jolsa, alexander.shishkin, eranian, hpa, mingo, linux-kernel,
acme, peterz, acme, vincent.weaver, tglx, torvalds,
linux-tip-commits, vincent.weaver
Cc: linux-arm-kernel
Hi, Peter:
First, thank you for your approval of my last patch and fix my bad description. And I have some questions about perf event and perf_fuzzer.
Recently I was using perf_fuzzer for testing in Hisilicon D03/D05(arm64, linux-4.10-rc1).
As we know perf_fuzzer will write a random value to procfs interface of perf event(like sysctl_perf_cpu_time_max_percent). The value may be 0 or 100, and I get logs like below:
----------------------------------
[ 4046.358811] perf: Dynamic interrupt throttling disabled, can hang your system!
----------------------------------
Most of the time, there is no problem, and the perf_fuzzer test can end without any warings or errors.
But there is a small probability that triggers the RCU and watchdog (The log is attached at the end). It hungs after local_irq_enable() in __do_softirq.
I think this is due to the dynamic interrupt throttling disabled and too many hardware interruptions come. So I limit the sysctl_perf_cpu_time_max_percent can only be set 1 to 99 in the kernel codes. I test more than 20 times in D03, and there are no errors or warnings in the test.
So I want to ask:
1)Is it a problem or not? (It has already given you a warning.)
2)If it is, where we will fix it more appropriate, perf_fuzzer(not set 0 or 100) or kernel(limit 1 to 99), or maybe it is the bug of hardware(too many hardware interruptions)?
Thanks.
Xiaojun.
------------------------------------
[ 3831.245881] perf: Dynamic interrupt throttling disabled, can hang your system!
[ 3844.421731] perf: Dynamic interrupt throttling disabled, can hang your system!
[ 4032.764228] hrtimer: interrupt took 2280 ns
[ 4035.494181] perf: interrupt took too long (1444 > 1), lowering kernel.perf_event_max_sample_rate to 16500
[ 4040.292886] perf: interrupt took too long (5 > 1), lowering kernel.perf_event_max_sample_rate to 5000000
[ 4041.388784] perf: Dynamic interrupt throttling disabled, can hang your system!
[ 4046.358811] perf: Dynamic interrupt throttling disabled, can hang your system!
10-175-112-211:~ #
10-175-112-211:~ #
10-175-112-211:~ # [ 4270.928905] perf: Dynamic interrupt throttling disabled, can hang your system!
[ 4270.945154] perf: Dynamic interrupt throttling disabled, can hang your system!
[ 4271.906280] perf: Dynamic interrupt throttling disabled, can hang your system!
[ 4294.491755] INFO: rcu_preempt self-detected stall on CPU
[ 4294.495755] INFO: rcu_preempt detected stalls on CPUs/tasks:
[ 4294.495761] 14-...: (6 GPs behind) idle=d65/140000000000002/0 softirq=6173/6173 fqs=2566
[ 4294.495761] (detected by 7, t=5252 jiffies, g=58964, c=58963, q=186)
[ 4294.495766] Task dump for CPU 14:
[ 4294.495768] perf_fuzzer R running task 0 31306 5036 0x00000202
[ 4294.495771] Call trace:
[ 4294.495778] [<ffff000008085634>] __switch_to+0x8c/0xac
[ 4294.495783] [<ffff00000815ef38>] event_function_call+0x88/0xf0
[ 4294.495785] [<ffff00000815f058>] _perf_event_enable+0x54/0x80
[ 4294.495788] [<ffff00000815ea2c>] perf_event_for_each_child+0x38/0x98
[ 4294.495791] [<ffff000008166a48>] perf_event_task_enable+0x58/0xa0
[ 4294.495794] [<ffff0000080d11e0>] SyS_prctl+0x2a0/0x3fc
[ 4294.495796] [<ffff000008082f8c>] __sys_trace_return+0x0/0x4
[ 4294.569983] 14-...: (6 GPs behind) idle=d65/140000000000002/0 softirq=6173/6173 fqs=2576
[ 4294.578228] (t=5272 jiffies g=58964 c=58963 q=186)
[ 4294.583187] Task dump for CPU 14:
[ 4294.586505] perf_fuzzer R running task 0 31306 5036 0x00000202
[ 4294.593541] Call trace:
[ 4294.595995] [<ffff0000080883d4>] dump_backtrace+0x0/0x240
[ 4294.601388] [<ffff000008088628>] show_stack+0x14/0x1c
[ 4294.606435] [<ffff0000080e5f84>] sched_show_task+0x130/0x174
[ 4294.612087] [<ffff0000080e8948>] dump_cpu_task+0x40/0x4c
[ 4294.617391] [<ffff00000816f944>] rcu_dump_cpu_stacks+0xa4/0xec
[ 4294.623215] [<ffff00000811a160>] rcu_check_callbacks+0x9d8/0xc70
[ 4294.629212] [<ffff00000811e0e8>] update_process_times+0x2c/0x58
[ 4294.635124] [<ffff00000812d1cc>] tick_sched_handle.isra.17+0x20/0x60
[ 4294.641465] [<ffff00000812d250>] tick_sched_timer+0x44/0x88
[ 4294.647027] [<ffff00000811e980>] __hrtimer_run_queues+0xe8/0x14c
[ 4294.653024] [<ffff00000811ef04>] hrtimer_interrupt+0x9c/0x1e0
[ 4294.658766] [<ffff000008793a94>] arch_timer_handler_virt+0x2c/0x38
[ 4294.664938] [<ffff00000810f554>] handle_percpu_devid_irq+0x78/0x12c
[ 4294.671195] [<ffff00000810a5ec>] generic_handle_irq+0x24/0x38
[ 4294.676932] [<ffff00000810ac84>] __handle_domain_irq+0x60/0xac
[ 4294.682756] [<ffff0000080816e4>] gic_handle_irq+0x74/0x174
[ 4294.688234] Exception stack(0xffff803ffffb2df0 to 0xffff803ffffb2f20)
[ 4294.694664] 2de0: ffff803ffffb2e20 0001000000000000
[ 4294.702480] 2e00: ffff803ffffb2f50 ffff0000080c29b0 0000000040000145 000000000000001b
[ 4294.710291] 2e20: 0000000000000700 ffff000008ed3300 ffff000008ed3300 0000803ff7214000
[ 4294.718106] 2e40: 000000000ccccccd 0000000000000020 001df84284000000 0000000001572fe1
[ 4294.725917] 2e60: 0000000000000000 0000000000000002 0000000000000002 0000ffffda3b0880
[ 4294.733729] 2e80: 0000000000000018 00000003e8000000 ffff000008ba6000 0000803ff7214000
[ 4294.741544] 2ea0: ffff0000080d0f40 000000000000e654 0000ffffda3b0690 ffff000008d9b000
[ 4294.749357] 2ec0: 0000000000000000 ffff000008d9fb08 ffff000008d9b000 ffff000008bc5728
[ 4294.757172] 2ee0: 000000000000001b ffff000008ba1000 ffff803ffffb3090 0000000000000282
[ 4294.764983] 2f00: ffff803f6e7bb200 ffff803ffffb2f50 ffff0000080c2e40 ffff803ffffb2f50
[ 4294.772798] [<ffff0000080827f4>] el1_irq+0xb4/0x128
[ 4294.777673] [<ffff0000080c2e40>] irq_exit+0xd0/0x118
[ 4294.782632] [<ffff00000810ac88>] __handle_domain_irq+0x64/0xac
[ 4294.788456] [<ffff0000080816e4>] gic_handle_irq+0x74/0x174
[ 4294.793934] Exception stack(0xffff803f5c07fbb0 to 0xffff803f5c07fce0)
[ 4294.800362] fba0: 0000000000000000 ffff803f6e7bb200
[ 4294.808177] fbc0: 0000000000008d5b 00000000000001c0 0000000000000000 0000000000000006
[ 4294.815992] fbe0: 0000000000000015 00000000dc7d24d2 00000000000000a7 00000000ffffff80
[ 4294.823803] fc00: 00000000ffffffd0 0000ffffda3b0880 0000000000000018 00000003e8000000
[ 4294.831618] fc20: 00028d3784000000 000069ade8000000 ffff0000080d0f40 0000ffff7b2584c0
[ 4294.839432] fc40: 0000ffffda3b0690 0000000000000140 0000000000000000 ffff803f6deaf108
[ 4294.847247] fc60: ffff00000815e680 ffff803f6dfa7000 ffff000008165b34 0000000000000000
[ 4294.855062] fc80: 00000000000000a7 ffff000008902000 ffff803f6e7bb200 ffff803f5c07fce0
[ 4294.862877] fca0: ffff0000081318f0 ffff803f5c07fce0 ffff0000081318f4 0000000020000145
[ 4294.870691] fcc0: ffff803f5c07fce0 ffff0000081318f0 0001000000000000 00000000000000a7
[ 4294.878506] [<ffff0000080827f4>] el1_irq+0xb4/0x128
[ 4294.883377] [<ffff0000081318f4>] generic_exec_single+0xe4/0x120
[ 4294.889289] [<ffff000008131a3c>] smp_call_function_single+0x10c/0x164
[ 4294.895719] [<ffff00000815ee94>] task_function_call+0x40/0x5c
[ 4294.901456] [<ffff00000815ef38>] event_function_call+0x88/0xf0
[ 4294.907282] [<ffff00000815f058>] _perf_event_enable+0x54/0x80
[ 4294.913018] [<ffff00000815ea2c>] perf_event_for_each_child+0x38/0x98
[ 4294.919359] [<ffff000008166a48>] perf_event_task_enable+0x58/0xa0
[ 4294.925443] [<ffff0000080d11e0>] SyS_prctl+0x2a0/0x3fc
[ 4294.930573] [<ffff000008082f8c>] __sys_trace_return+0x0/0x4
10-175-112-211:~ #
10-175-112-211:~ # [ 4321.341680] NMI watchdog: BUG: soft lockup - CPU#14 stuck for 22s! [perf_fuzzer:31306]
[ 4321.349583] Modules linked in:
[ 4321.352641]
[ 4321.354146] CPU: 14 PID: 31306 Comm: perf_fuzzer Not tainted 4.10.0-rc1-ga1d2732-dirty #7
[ 4321.362306] Hardware name: Huawei Taishan 2180 /BC11SPCC, BIOS 1.31 06/23/2016
[ 4321.369515] task: ffff803f6e7bb200 task.stack: ffff803f5c07c000
[ 4321.375428] PC is at __do_softirq+0xc0/0x240
[ 4321.379698] LR is at irq_exit+0xd0/0x118
[ 4321.383618] pc : [<ffff0000080c29b0>] lr : [<ffff0000080c2e40>] pstate: 40000145
[ 4321.390999] sp : ffff803ffffb2f50
[ 4321.394314] x29: ffff803ffffb2f50 x28: ffff803f6e7bb200
[ 4321.399619] x27: 0000000000000282 x26: ffff803ffffb3090
[ 4321.404922] x25: ffff000008ba1000 x24: 000000000000001b
[ 4321.410229] x23: ffff000008bc5728 x22: ffff000008d9b000
[ 4321.415532] x21: ffff000008d9fb08 x20: 0000000000000000
[ 4321.420836] x19: ffff000008d9b000 x18: 0000ffffda3b0690
[ 4321.426139] x17: 000000000000e654 x16: ffff0000080d0f40
[ 4321.431444] x15: 0000803ff7214000 x14: ffff000008ba6000
[ 4321.436747] x13: 00000003e8000000 x12: 0000000000000018
[ 4321.442053] x11: 0000ffffda3b0880 x10: 0000000000000002
[ 4321.447356] x9 : 0000000000000002 x8 : 0000000000000000
[ 4321.452659] x7 : 0000000001572fe1 x6 : 001df84284000000
[ 4321.457965] x5 : 0000000000000020 x4 : 000000000ccccccd
[ 4321.463270] x3 : 0000803ff7214000 x2 : ffff000008ed3300
[ 4321.468577] x1 : ffff000008ed3300 x0 : 0000000000000700
[ 4321.473882]
Message from syslogd@localhost at Feb 25 11:07:22 ...
kernel:[ 4321.341680] NMI watchdog: BUG: soft lockup - CPU#14 stuck for 22s! [perf_fuzzer:31306]
10-175-112-211:~ #
10-175-112-211:~ # [ 4349.341680] NMI watchdog: BUG: soft lockup - CPU#14 stuck for 22s! [perf_fuzzer:31306]
[ 4349.349580] Modules linked in:
[ 4349.352637]
[ 4349.354138] CPU: 14 PID: 31306 Comm: perf_fuzzer Tainted: G L 4.10.0-rc1-ga1d2732-dirty #7
[ 4349.363506] Hardware name: Huawei Taishan 2180 /BC11SPCC, BIOS 1.31 06/23/2016
[ 4349.370714] task: ffff803f6e7bb200 task.stack: ffff803f5c07c000
[ 4349.376624] PC is at __do_softirq+0xc0/0x240
[ 4349.380893] LR is at irq_exit+0xd0/0x118
[ 4349.384815] pc : [<ffff0000080c29b0>] lr : [<ffff0000080c2e40>] pstate: 40000145
[ 4349.392195] sp : ffff803ffffb2f50
[ 4349.395513] x29: ffff803ffffb2f50 x28: ffff803f6e7bb200
[ 4349.400817] x27: 0000000000000282 x26: ffff803ffffb3090
[ 4349.406121] x25: ffff000008ba1000 x24: 000000000000001b
[ 4349.411424] x23: ffff000008bc5728 x22: ffff000008d9b000
[ 4349.416727] x21: ffff000008d9fb08 x20: 0000000000000000
[ 4349.422032] x19: ffff000008d9b000 x18: 0000ffffda3b0690
[ 4349.427337] x17: 000000000000e654 x16: ffff0000080d0f40
[ 4349.432640] x15: 0000803ff7214000 x14: ffff000008ba6000
[ 4349.437944] x13: 00000003e8000000 x12: 0000000000000018
[ 4349.443248] x11: 0000ffffda3b0880 x10: 0000000000000002
[ 4349.448552] x9 : 0000000000000002 x8 : 0000000000000000
[ 4349.453856] x7 : 0000000001572fe1 x6 : 001df84284000000
[ 4349.459162] x5 : 0000000000000020 x4 : 000000000ccccccd
[ 4349.464465] x3 : 0000803ff7214000 x2 : ffff000008ed3300
[ 4349.469769] x1 : ffff000008ed3300 x0 : 0000000000000700
[ 4349.475072]
------------------------------------
part of objdump code:
ffff0000080c29a8: b820683f str wzr, [x1,x0]
return flags;
}
static inline void arch_local_irq_enable(void)
{
asm volatile(
ffff0000080c29ac: d50342ff msr daifclr, #0x2
local_irq_enable();
h = softirq_vec;
ffff0000080c29b0: 90006920 adrp x0, ffff000008de6000 <boot_args>
while ((softirq_bit = ffs(pending))) {
unsigned int vec_nr;
int prev_count;
h += softirq_bit - 1;
ffff0000080c29b4: 928000f4 mov x20, #0xfffffffffffffff8 // #-8
/* Reset the pending bitmask before enabling irqs */
set_softirq_pending(0);
local_irq_enable();
h = softirq_vec;
ffff0000080c29b8: 9106001c add x28, x0, #0x180
unsigned int vec_nr;
int prev_count;
h += softirq_bit - 1;
-----------------------------------------
On 2017/2/24 17:15, tip-bot for Tan Xiaojun wrote:
> Commit-ID: 1572e45a924f254d9570093abde46430c3172e3d
> Gitweb: http://git.kernel.org/tip/1572e45a924f254d9570093abde46430c3172e3d
> Author: Tan Xiaojun <tanxiaojun@huawei.com>
> AuthorDate: Thu, 23 Feb 2017 14:04:39 +0800
> Committer: Ingo Molnar <mingo@kernel.org>
> CommitDate: Fri, 24 Feb 2017 08:56:33 +0100
>
> perf/core: Fix the perf_cpu_time_max_percent check
>
> Use "proc_dointvec_minmax" instead of "proc_dointvec" to check the input
> value from user-space.
>
> If not, we can set a big value and some vars will overflow like
> "sysctl_perf_event_sample_rate" which will cause a lot of unexpected
> problems.
>
> Signed-off-by: Tan Xiaojun <tanxiaojun@huawei.com>
> Signed-off-by: Peter Zijlstra (Intel) <peterz@infradead.org>
> Cc: <acme@kernel.org>
> Cc: <alexander.shishkin@linux.intel.com>
> Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
> Cc: Arnaldo Carvalho de Melo <acme@redhat.com>
> Cc: Jiri Olsa <jolsa@redhat.com>
> Cc: Linus Torvalds <torvalds@linux-foundation.org>
> Cc: Peter Zijlstra <peterz@infradead.org>
> Cc: Stephane Eranian <eranian@google.com>
> Cc: Thomas Gleixner <tglx@linutronix.de>
> Cc: Vince Weaver <vincent.weaver@maine.edu>
> Link: http://lkml.kernel.org/r/1487829879-56237-1-git-send-email-tanxiaojun@huawei.com
> Signed-off-by: Ingo Molnar <mingo@kernel.org>
> ---
> kernel/events/core.c | 2 +-
> 1 file changed, 1 insertion(+), 1 deletion(-)
>
> diff --git a/kernel/events/core.c b/kernel/events/core.c
> index d4e3f8d..c1c1cdf 100644
> --- a/kernel/events/core.c
> +++ b/kernel/events/core.c
> @@ -455,7 +455,7 @@ int perf_cpu_time_max_percent_handler(struct ctl_table *table, int write,
> void __user *buffer, size_t *lenp,
> loff_t *ppos)
> {
> - int ret = proc_dointvec(table, write, buffer, lenp, ppos);
> + int ret = proc_dointvec_minmax(table, write, buffer, lenp, ppos);
>
> if (ret || !write)
> return ret;
>
> .
>
^ permalink raw reply [flat|nested] 18+ messages in thread
* [tip:perf/urgent] perf/core: Fix the perf_cpu_time_max_percent check
@ 2017-02-25 8:10 ` Tan Xiaojun
0 siblings, 0 replies; 18+ messages in thread
From: Tan Xiaojun @ 2017-02-25 8:10 UTC (permalink / raw)
To: linux-arm-kernel
Hi, Peter:
First, thank you for your approval of my last patch and fix my bad description. And I have some questions about perf event and perf_fuzzer.
Recently I was using perf_fuzzer for testing in Hisilicon D03/D05(arm64, linux-4.10-rc1).
As we know perf_fuzzer will write a random value to procfs interface of perf event(like sysctl_perf_cpu_time_max_percent). The value may be 0 or 100, and I get logs like below:
----------------------------------
[ 4046.358811] perf: Dynamic interrupt throttling disabled, can hang your system!
----------------------------------
Most of the time, there is no problem, and the perf_fuzzer test can end without any warings or errors.
But there is a small probability that triggers the RCU and watchdog (The log is attached at the end). It hungs after local_irq_enable() in __do_softirq.
I think this is due to the dynamic interrupt throttling disabled and too many hardware interruptions come. So I limit the sysctl_perf_cpu_time_max_percent can only be set 1 to 99 in the kernel codes. I test more than 20 times in D03, and there are no errors or warnings in the test.
So I want to ask:
1)Is it a problem or not? (It has already given you a warning.)
2)If it is, where we will fix it more appropriate, perf_fuzzer(not set 0 or 100) or kernel(limit 1 to 99), or maybe it is the bug of hardware(too many hardware interruptions)?
Thanks.
Xiaojun.
------------------------------------
[ 3831.245881] perf: Dynamic interrupt throttling disabled, can hang your system!
[ 3844.421731] perf: Dynamic interrupt throttling disabled, can hang your system!
[ 4032.764228] hrtimer: interrupt took 2280 ns
[ 4035.494181] perf: interrupt took too long (1444 > 1), lowering kernel.perf_event_max_sample_rate to 16500
[ 4040.292886] perf: interrupt took too long (5 > 1), lowering kernel.perf_event_max_sample_rate to 5000000
[ 4041.388784] perf: Dynamic interrupt throttling disabled, can hang your system!
[ 4046.358811] perf: Dynamic interrupt throttling disabled, can hang your system!
10-175-112-211:~ #
10-175-112-211:~ #
10-175-112-211:~ # [ 4270.928905] perf: Dynamic interrupt throttling disabled, can hang your system!
[ 4270.945154] perf: Dynamic interrupt throttling disabled, can hang your system!
[ 4271.906280] perf: Dynamic interrupt throttling disabled, can hang your system!
[ 4294.491755] INFO: rcu_preempt self-detected stall on CPU
[ 4294.495755] INFO: rcu_preempt detected stalls on CPUs/tasks:
[ 4294.495761] 14-...: (6 GPs behind) idle=d65/140000000000002/0 softirq=6173/6173 fqs=2566
[ 4294.495761] (detected by 7, t=5252 jiffies, g=58964, c=58963, q=186)
[ 4294.495766] Task dump for CPU 14:
[ 4294.495768] perf_fuzzer R running task 0 31306 5036 0x00000202
[ 4294.495771] Call trace:
[ 4294.495778] [<ffff000008085634>] __switch_to+0x8c/0xac
[ 4294.495783] [<ffff00000815ef38>] event_function_call+0x88/0xf0
[ 4294.495785] [<ffff00000815f058>] _perf_event_enable+0x54/0x80
[ 4294.495788] [<ffff00000815ea2c>] perf_event_for_each_child+0x38/0x98
[ 4294.495791] [<ffff000008166a48>] perf_event_task_enable+0x58/0xa0
[ 4294.495794] [<ffff0000080d11e0>] SyS_prctl+0x2a0/0x3fc
[ 4294.495796] [<ffff000008082f8c>] __sys_trace_return+0x0/0x4
[ 4294.569983] 14-...: (6 GPs behind) idle=d65/140000000000002/0 softirq=6173/6173 fqs=2576
[ 4294.578228] (t=5272 jiffies g=58964 c=58963 q=186)
[ 4294.583187] Task dump for CPU 14:
[ 4294.586505] perf_fuzzer R running task 0 31306 5036 0x00000202
[ 4294.593541] Call trace:
[ 4294.595995] [<ffff0000080883d4>] dump_backtrace+0x0/0x240
[ 4294.601388] [<ffff000008088628>] show_stack+0x14/0x1c
[ 4294.606435] [<ffff0000080e5f84>] sched_show_task+0x130/0x174
[ 4294.612087] [<ffff0000080e8948>] dump_cpu_task+0x40/0x4c
[ 4294.617391] [<ffff00000816f944>] rcu_dump_cpu_stacks+0xa4/0xec
[ 4294.623215] [<ffff00000811a160>] rcu_check_callbacks+0x9d8/0xc70
[ 4294.629212] [<ffff00000811e0e8>] update_process_times+0x2c/0x58
[ 4294.635124] [<ffff00000812d1cc>] tick_sched_handle.isra.17+0x20/0x60
[ 4294.641465] [<ffff00000812d250>] tick_sched_timer+0x44/0x88
[ 4294.647027] [<ffff00000811e980>] __hrtimer_run_queues+0xe8/0x14c
[ 4294.653024] [<ffff00000811ef04>] hrtimer_interrupt+0x9c/0x1e0
[ 4294.658766] [<ffff000008793a94>] arch_timer_handler_virt+0x2c/0x38
[ 4294.664938] [<ffff00000810f554>] handle_percpu_devid_irq+0x78/0x12c
[ 4294.671195] [<ffff00000810a5ec>] generic_handle_irq+0x24/0x38
[ 4294.676932] [<ffff00000810ac84>] __handle_domain_irq+0x60/0xac
[ 4294.682756] [<ffff0000080816e4>] gic_handle_irq+0x74/0x174
[ 4294.688234] Exception stack(0xffff803ffffb2df0 to 0xffff803ffffb2f20)
[ 4294.694664] 2de0: ffff803ffffb2e20 0001000000000000
[ 4294.702480] 2e00: ffff803ffffb2f50 ffff0000080c29b0 0000000040000145 000000000000001b
[ 4294.710291] 2e20: 0000000000000700 ffff000008ed3300 ffff000008ed3300 0000803ff7214000
[ 4294.718106] 2e40: 000000000ccccccd 0000000000000020 001df84284000000 0000000001572fe1
[ 4294.725917] 2e60: 0000000000000000 0000000000000002 0000000000000002 0000ffffda3b0880
[ 4294.733729] 2e80: 0000000000000018 00000003e8000000 ffff000008ba6000 0000803ff7214000
[ 4294.741544] 2ea0: ffff0000080d0f40 000000000000e654 0000ffffda3b0690 ffff000008d9b000
[ 4294.749357] 2ec0: 0000000000000000 ffff000008d9fb08 ffff000008d9b000 ffff000008bc5728
[ 4294.757172] 2ee0: 000000000000001b ffff000008ba1000 ffff803ffffb3090 0000000000000282
[ 4294.764983] 2f00: ffff803f6e7bb200 ffff803ffffb2f50 ffff0000080c2e40 ffff803ffffb2f50
[ 4294.772798] [<ffff0000080827f4>] el1_irq+0xb4/0x128
[ 4294.777673] [<ffff0000080c2e40>] irq_exit+0xd0/0x118
[ 4294.782632] [<ffff00000810ac88>] __handle_domain_irq+0x64/0xac
[ 4294.788456] [<ffff0000080816e4>] gic_handle_irq+0x74/0x174
[ 4294.793934] Exception stack(0xffff803f5c07fbb0 to 0xffff803f5c07fce0)
[ 4294.800362] fba0: 0000000000000000 ffff803f6e7bb200
[ 4294.808177] fbc0: 0000000000008d5b 00000000000001c0 0000000000000000 0000000000000006
[ 4294.815992] fbe0: 0000000000000015 00000000dc7d24d2 00000000000000a7 00000000ffffff80
[ 4294.823803] fc00: 00000000ffffffd0 0000ffffda3b0880 0000000000000018 00000003e8000000
[ 4294.831618] fc20: 00028d3784000000 000069ade8000000 ffff0000080d0f40 0000ffff7b2584c0
[ 4294.839432] fc40: 0000ffffda3b0690 0000000000000140 0000000000000000 ffff803f6deaf108
[ 4294.847247] fc60: ffff00000815e680 ffff803f6dfa7000 ffff000008165b34 0000000000000000
[ 4294.855062] fc80: 00000000000000a7 ffff000008902000 ffff803f6e7bb200 ffff803f5c07fce0
[ 4294.862877] fca0: ffff0000081318f0 ffff803f5c07fce0 ffff0000081318f4 0000000020000145
[ 4294.870691] fcc0: ffff803f5c07fce0 ffff0000081318f0 0001000000000000 00000000000000a7
[ 4294.878506] [<ffff0000080827f4>] el1_irq+0xb4/0x128
[ 4294.883377] [<ffff0000081318f4>] generic_exec_single+0xe4/0x120
[ 4294.889289] [<ffff000008131a3c>] smp_call_function_single+0x10c/0x164
[ 4294.895719] [<ffff00000815ee94>] task_function_call+0x40/0x5c
[ 4294.901456] [<ffff00000815ef38>] event_function_call+0x88/0xf0
[ 4294.907282] [<ffff00000815f058>] _perf_event_enable+0x54/0x80
[ 4294.913018] [<ffff00000815ea2c>] perf_event_for_each_child+0x38/0x98
[ 4294.919359] [<ffff000008166a48>] perf_event_task_enable+0x58/0xa0
[ 4294.925443] [<ffff0000080d11e0>] SyS_prctl+0x2a0/0x3fc
[ 4294.930573] [<ffff000008082f8c>] __sys_trace_return+0x0/0x4
10-175-112-211:~ #
10-175-112-211:~ # [ 4321.341680] NMI watchdog: BUG: soft lockup - CPU#14 stuck for 22s! [perf_fuzzer:31306]
[ 4321.349583] Modules linked in:
[ 4321.352641]
[ 4321.354146] CPU: 14 PID: 31306 Comm: perf_fuzzer Not tainted 4.10.0-rc1-ga1d2732-dirty #7
[ 4321.362306] Hardware name: Huawei Taishan 2180 /BC11SPCC, BIOS 1.31 06/23/2016
[ 4321.369515] task: ffff803f6e7bb200 task.stack: ffff803f5c07c000
[ 4321.375428] PC is at __do_softirq+0xc0/0x240
[ 4321.379698] LR is at irq_exit+0xd0/0x118
[ 4321.383618] pc : [<ffff0000080c29b0>] lr : [<ffff0000080c2e40>] pstate: 40000145
[ 4321.390999] sp : ffff803ffffb2f50
[ 4321.394314] x29: ffff803ffffb2f50 x28: ffff803f6e7bb200
[ 4321.399619] x27: 0000000000000282 x26: ffff803ffffb3090
[ 4321.404922] x25: ffff000008ba1000 x24: 000000000000001b
[ 4321.410229] x23: ffff000008bc5728 x22: ffff000008d9b000
[ 4321.415532] x21: ffff000008d9fb08 x20: 0000000000000000
[ 4321.420836] x19: ffff000008d9b000 x18: 0000ffffda3b0690
[ 4321.426139] x17: 000000000000e654 x16: ffff0000080d0f40
[ 4321.431444] x15: 0000803ff7214000 x14: ffff000008ba6000
[ 4321.436747] x13: 00000003e8000000 x12: 0000000000000018
[ 4321.442053] x11: 0000ffffda3b0880 x10: 0000000000000002
[ 4321.447356] x9 : 0000000000000002 x8 : 0000000000000000
[ 4321.452659] x7 : 0000000001572fe1 x6 : 001df84284000000
[ 4321.457965] x5 : 0000000000000020 x4 : 000000000ccccccd
[ 4321.463270] x3 : 0000803ff7214000 x2 : ffff000008ed3300
[ 4321.468577] x1 : ffff000008ed3300 x0 : 0000000000000700
[ 4321.473882]
Message from syslogd at localhost at Feb 25 11:07:22 ...
kernel:[ 4321.341680] NMI watchdog: BUG: soft lockup - CPU#14 stuck for 22s! [perf_fuzzer:31306]
10-175-112-211:~ #
10-175-112-211:~ # [ 4349.341680] NMI watchdog: BUG: soft lockup - CPU#14 stuck for 22s! [perf_fuzzer:31306]
[ 4349.349580] Modules linked in:
[ 4349.352637]
[ 4349.354138] CPU: 14 PID: 31306 Comm: perf_fuzzer Tainted: G L 4.10.0-rc1-ga1d2732-dirty #7
[ 4349.363506] Hardware name: Huawei Taishan 2180 /BC11SPCC, BIOS 1.31 06/23/2016
[ 4349.370714] task: ffff803f6e7bb200 task.stack: ffff803f5c07c000
[ 4349.376624] PC is at __do_softirq+0xc0/0x240
[ 4349.380893] LR is at irq_exit+0xd0/0x118
[ 4349.384815] pc : [<ffff0000080c29b0>] lr : [<ffff0000080c2e40>] pstate: 40000145
[ 4349.392195] sp : ffff803ffffb2f50
[ 4349.395513] x29: ffff803ffffb2f50 x28: ffff803f6e7bb200
[ 4349.400817] x27: 0000000000000282 x26: ffff803ffffb3090
[ 4349.406121] x25: ffff000008ba1000 x24: 000000000000001b
[ 4349.411424] x23: ffff000008bc5728 x22: ffff000008d9b000
[ 4349.416727] x21: ffff000008d9fb08 x20: 0000000000000000
[ 4349.422032] x19: ffff000008d9b000 x18: 0000ffffda3b0690
[ 4349.427337] x17: 000000000000e654 x16: ffff0000080d0f40
[ 4349.432640] x15: 0000803ff7214000 x14: ffff000008ba6000
[ 4349.437944] x13: 00000003e8000000 x12: 0000000000000018
[ 4349.443248] x11: 0000ffffda3b0880 x10: 0000000000000002
[ 4349.448552] x9 : 0000000000000002 x8 : 0000000000000000
[ 4349.453856] x7 : 0000000001572fe1 x6 : 001df84284000000
[ 4349.459162] x5 : 0000000000000020 x4 : 000000000ccccccd
[ 4349.464465] x3 : 0000803ff7214000 x2 : ffff000008ed3300
[ 4349.469769] x1 : ffff000008ed3300 x0 : 0000000000000700
[ 4349.475072]
------------------------------------
part of objdump code:
ffff0000080c29a8: b820683f str wzr, [x1,x0]
return flags;
}
static inline void arch_local_irq_enable(void)
{
asm volatile(
ffff0000080c29ac: d50342ff msr daifclr, #0x2
local_irq_enable();
h = softirq_vec;
ffff0000080c29b0: 90006920 adrp x0, ffff000008de6000 <boot_args>
while ((softirq_bit = ffs(pending))) {
unsigned int vec_nr;
int prev_count;
h += softirq_bit - 1;
ffff0000080c29b4: 928000f4 mov x20, #0xfffffffffffffff8 // #-8
/* Reset the pending bitmask before enabling irqs */
set_softirq_pending(0);
local_irq_enable();
h = softirq_vec;
ffff0000080c29b8: 9106001c add x28, x0, #0x180
unsigned int vec_nr;
int prev_count;
h += softirq_bit - 1;
-----------------------------------------
On 2017/2/24 17:15, tip-bot for Tan Xiaojun wrote:
> Commit-ID: 1572e45a924f254d9570093abde46430c3172e3d
> Gitweb: http://git.kernel.org/tip/1572e45a924f254d9570093abde46430c3172e3d
> Author: Tan Xiaojun <tanxiaojun@huawei.com>
> AuthorDate: Thu, 23 Feb 2017 14:04:39 +0800
> Committer: Ingo Molnar <mingo@kernel.org>
> CommitDate: Fri, 24 Feb 2017 08:56:33 +0100
>
> perf/core: Fix the perf_cpu_time_max_percent check
>
> Use "proc_dointvec_minmax" instead of "proc_dointvec" to check the input
> value from user-space.
>
> If not, we can set a big value and some vars will overflow like
> "sysctl_perf_event_sample_rate" which will cause a lot of unexpected
> problems.
>
> Signed-off-by: Tan Xiaojun <tanxiaojun@huawei.com>
> Signed-off-by: Peter Zijlstra (Intel) <peterz@infradead.org>
> Cc: <acme@kernel.org>
> Cc: <alexander.shishkin@linux.intel.com>
> Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
> Cc: Arnaldo Carvalho de Melo <acme@redhat.com>
> Cc: Jiri Olsa <jolsa@redhat.com>
> Cc: Linus Torvalds <torvalds@linux-foundation.org>
> Cc: Peter Zijlstra <peterz@infradead.org>
> Cc: Stephane Eranian <eranian@google.com>
> Cc: Thomas Gleixner <tglx@linutronix.de>
> Cc: Vince Weaver <vincent.weaver@maine.edu>
> Link: http://lkml.kernel.org/r/1487829879-56237-1-git-send-email-tanxiaojun at huawei.com
> Signed-off-by: Ingo Molnar <mingo@kernel.org>
> ---
> kernel/events/core.c | 2 +-
> 1 file changed, 1 insertion(+), 1 deletion(-)
>
> diff --git a/kernel/events/core.c b/kernel/events/core.c
> index d4e3f8d..c1c1cdf 100644
> --- a/kernel/events/core.c
> +++ b/kernel/events/core.c
> @@ -455,7 +455,7 @@ int perf_cpu_time_max_percent_handler(struct ctl_table *table, int write,
> void __user *buffer, size_t *lenp,
> loff_t *ppos)
> {
> - int ret = proc_dointvec(table, write, buffer, lenp, ppos);
> + int ret = proc_dointvec_minmax(table, write, buffer, lenp, ppos);
>
> if (ret || !write)
> return ret;
>
> .
>
^ permalink raw reply [flat|nested] 18+ messages in thread
* Re: [tip:perf/urgent] perf/core: Fix the perf_cpu_time_max_percent check
2017-02-25 8:10 ` Tan Xiaojun
@ 2017-02-25 9:51 ` Peter Zijlstra
-1 siblings, 0 replies; 18+ messages in thread
From: Peter Zijlstra @ 2017-02-25 9:51 UTC (permalink / raw)
To: Tan Xiaojun
Cc: jolsa, alexander.shishkin, eranian, hpa, mingo, linux-kernel,
acme, acme, vincent.weaver, tglx, torvalds, linux-tip-commits,
linux-arm-kernel
On Sat, Feb 25, 2017 at 04:10:37PM +0800, Tan Xiaojun wrote:
> Recently I was using perf_fuzzer for testing in Hisilicon
> D03/D05(arm64, linux-4.10-rc1).
>
> As we know perf_fuzzer will write a random value to procfs interface
> of perf event(like sysctl_perf_cpu_time_max_percent). The value may be
> 0 or 100, and I get logs like below:
>
> ----------------------------------
> [ 4046.358811] perf: Dynamic interrupt throttling disabled, can hang your system!
> ----------------------------------
>
> Most of the time, there is no problem, and the perf_fuzzer test can
> end without any warings or errors. But there is a small probability
> that triggers the RCU and watchdog (The log is attached at the end).
> It hungs after local_irq_enable() in __do_softirq.
>
> I think this is due to the dynamic interrupt throttling disabled and
> too many hardware interruptions come. So I limit the
> sysctl_perf_cpu_time_max_percent can only be set 1 to 99 in the kernel
> codes. I test more than 20 times in D03, and there are no errors or
> warnings in the test.
>
> So I want to ask:
>
> 1)Is it a problem or not? (It has already given you a warning.)
>
> 2)If it is, where we will fix it more appropriate, perf_fuzzer(not set
> 0 or 100) or kernel(limit 1 to 99), or maybe it is the bug of
> hardware(too many hardware interruptions)?
I think the best would be if the fuzzer would not set 0,100, those are
clearly 'unsafe' settings and you pretty much get to keep the pieces.
I would like to preserve these settings for people that 'know' what
they're doing and are willing to take the risk, but clearly, when you
take the guard-rails off, things can come apart.
^ permalink raw reply [flat|nested] 18+ messages in thread
* [tip:perf/urgent] perf/core: Fix the perf_cpu_time_max_percent check
@ 2017-02-25 9:51 ` Peter Zijlstra
0 siblings, 0 replies; 18+ messages in thread
From: Peter Zijlstra @ 2017-02-25 9:51 UTC (permalink / raw)
To: linux-arm-kernel
On Sat, Feb 25, 2017 at 04:10:37PM +0800, Tan Xiaojun wrote:
> Recently I was using perf_fuzzer for testing in Hisilicon
> D03/D05(arm64, linux-4.10-rc1).
>
> As we know perf_fuzzer will write a random value to procfs interface
> of perf event(like sysctl_perf_cpu_time_max_percent). The value may be
> 0 or 100, and I get logs like below:
>
> ----------------------------------
> [ 4046.358811] perf: Dynamic interrupt throttling disabled, can hang your system!
> ----------------------------------
>
> Most of the time, there is no problem, and the perf_fuzzer test can
> end without any warings or errors. But there is a small probability
> that triggers the RCU and watchdog (The log is attached at the end).
> It hungs after local_irq_enable() in __do_softirq.
>
> I think this is due to the dynamic interrupt throttling disabled and
> too many hardware interruptions come. So I limit the
> sysctl_perf_cpu_time_max_percent can only be set 1 to 99 in the kernel
> codes. I test more than 20 times in D03, and there are no errors or
> warnings in the test.
>
> So I want to ask:
>
> 1)Is it a problem or not? (It has already given you a warning.)
>
> 2)If it is, where we will fix it more appropriate, perf_fuzzer(not set
> 0 or 100) or kernel(limit 1 to 99), or maybe it is the bug of
> hardware(too many hardware interruptions)?
I think the best would be if the fuzzer would not set 0,100, those are
clearly 'unsafe' settings and you pretty much get to keep the pieces.
I would like to preserve these settings for people that 'know' what
they're doing and are willing to take the risk, but clearly, when you
take the guard-rails off, things can come apart.
^ permalink raw reply [flat|nested] 18+ messages in thread
* Re: [tip:perf/urgent] perf/core: Fix the perf_cpu_time_max_percent check
2017-02-25 9:51 ` Peter Zijlstra
@ 2017-02-27 0:36 ` Tan Xiaojun
-1 siblings, 0 replies; 18+ messages in thread
From: Tan Xiaojun @ 2017-02-27 0:36 UTC (permalink / raw)
To: Peter Zijlstra
Cc: jolsa, alexander.shishkin, eranian, hpa, mingo, linux-kernel,
acme, acme, vincent.weaver, tglx, torvalds, linux-tip-commits,
linux-arm-kernel
On 2017/2/25 17:51, Peter Zijlstra wrote:
> On Sat, Feb 25, 2017 at 04:10:37PM +0800, Tan Xiaojun wrote:
>
>> Recently I was using perf_fuzzer for testing in Hisilicon
>> D03/D05(arm64, linux-4.10-rc1).
>>
>> As we know perf_fuzzer will write a random value to procfs interface
>> of perf event(like sysctl_perf_cpu_time_max_percent). The value may be
>> 0 or 100, and I get logs like below:
>>
>> ----------------------------------
>> [ 4046.358811] perf: Dynamic interrupt throttling disabled, can hang your system!
>> ----------------------------------
>>
>> Most of the time, there is no problem, and the perf_fuzzer test can
>> end without any warings or errors. But there is a small probability
>> that triggers the RCU and watchdog (The log is attached at the end).
>> It hungs after local_irq_enable() in __do_softirq.
>>
>> I think this is due to the dynamic interrupt throttling disabled and
>> too many hardware interruptions come. So I limit the
>> sysctl_perf_cpu_time_max_percent can only be set 1 to 99 in the kernel
>> codes. I test more than 20 times in D03, and there are no errors or
>> warnings in the test.
>>
>> So I want to ask:
>>
>> 1)Is it a problem or not? (It has already given you a warning.)
>>
>> 2)If it is, where we will fix it more appropriate, perf_fuzzer(not set
>> 0 or 100) or kernel(limit 1 to 99), or maybe it is the bug of
>> hardware(too many hardware interruptions)?
>
> I think the best would be if the fuzzer would not set 0,100, those are
> clearly 'unsafe' settings and you pretty much get to keep the pieces.
>
> I would like to preserve these settings for people that 'know' what
> they're doing and are willing to take the risk, but clearly, when you
> take the guard-rails off, things can come apart.
>
OK. It makes sense, I agree.
Thank you for your answer.
Xiaojun.
> .
>
^ permalink raw reply [flat|nested] 18+ messages in thread
* [tip:perf/urgent] perf/core: Fix the perf_cpu_time_max_percent check
@ 2017-02-27 0:36 ` Tan Xiaojun
0 siblings, 0 replies; 18+ messages in thread
From: Tan Xiaojun @ 2017-02-27 0:36 UTC (permalink / raw)
To: linux-arm-kernel
On 2017/2/25 17:51, Peter Zijlstra wrote:
> On Sat, Feb 25, 2017 at 04:10:37PM +0800, Tan Xiaojun wrote:
>
>> Recently I was using perf_fuzzer for testing in Hisilicon
>> D03/D05(arm64, linux-4.10-rc1).
>>
>> As we know perf_fuzzer will write a random value to procfs interface
>> of perf event(like sysctl_perf_cpu_time_max_percent). The value may be
>> 0 or 100, and I get logs like below:
>>
>> ----------------------------------
>> [ 4046.358811] perf: Dynamic interrupt throttling disabled, can hang your system!
>> ----------------------------------
>>
>> Most of the time, there is no problem, and the perf_fuzzer test can
>> end without any warings or errors. But there is a small probability
>> that triggers the RCU and watchdog (The log is attached at the end).
>> It hungs after local_irq_enable() in __do_softirq.
>>
>> I think this is due to the dynamic interrupt throttling disabled and
>> too many hardware interruptions come. So I limit the
>> sysctl_perf_cpu_time_max_percent can only be set 1 to 99 in the kernel
>> codes. I test more than 20 times in D03, and there are no errors or
>> warnings in the test.
>>
>> So I want to ask:
>>
>> 1)Is it a problem or not? (It has already given you a warning.)
>>
>> 2)If it is, where we will fix it more appropriate, perf_fuzzer(not set
>> 0 or 100) or kernel(limit 1 to 99), or maybe it is the bug of
>> hardware(too many hardware interruptions)?
>
> I think the best would be if the fuzzer would not set 0,100, those are
> clearly 'unsafe' settings and you pretty much get to keep the pieces.
>
> I would like to preserve these settings for people that 'know' what
> they're doing and are willing to take the risk, but clearly, when you
> take the guard-rails off, things can come apart.
>
OK. It makes sense, I agree.
Thank you for your answer.
Xiaojun.
> .
>
^ permalink raw reply [flat|nested] 18+ messages in thread
* Re: [tip:perf/urgent] perf/core: Fix the perf_cpu_time_max_percent check
2017-02-25 9:51 ` Peter Zijlstra
(?)
(?)
@ 2017-03-13 18:35 ` Vince Weaver
2017-03-14 1:52 ` Tan Xiaojun
-1 siblings, 1 reply; 18+ messages in thread
From: Vince Weaver @ 2017-03-13 18:35 UTC (permalink / raw)
To: Peter Zijlstra
Cc: Tan Xiaojun, jolsa, alexander.shishkin, eranian, mingo, linux-kernel
On Sat, 25 Feb 2017, Peter Zijlstra wrote:
> On Sat, Feb 25, 2017 at 04:10:37PM +0800, Tan Xiaojun wrote:
>
> > 2)If it is, where we will fix it more appropriate, perf_fuzzer(not set
> > 0 or 100) or kernel(limit 1 to 99), or maybe it is the bug of
> > hardware(too many hardware interruptions)?
>
> I think the best would be if the fuzzer would not set 0,100, those are
> clearly 'unsafe' settings and you pretty much get to keep the pieces.
>
> I would like to preserve these settings for people that 'know' what
> they're doing and are willing to take the risk, but clearly, when you
> take the guard-rails off, things can come apart.
sorry for the delay responding, these e-mails ended up in the spam folder
somehow.
I could add a new "avoid stupid things as root" flag for the perf_fuzzer.
Besides this issue, are there other known things to skip?
Generally running a fuzzer as root can be a bad idea which is why I don't
test that use case very often.
I think there were other issues in the past, like certain ftrace
combinations being known to lock the system.
Vince
^ permalink raw reply [flat|nested] 18+ messages in thread
* Re: [tip:perf/urgent] perf/core: Fix the perf_cpu_time_max_percent check
2017-03-13 18:35 ` Vince Weaver
@ 2017-03-14 1:52 ` Tan Xiaojun
0 siblings, 0 replies; 18+ messages in thread
From: Tan Xiaojun @ 2017-03-14 1:52 UTC (permalink / raw)
To: Vince Weaver, Peter Zijlstra
Cc: jolsa, alexander.shishkin, eranian, mingo, linux-kernel
On 2017/3/14 2:35, Vince Weaver wrote:
> On Sat, 25 Feb 2017, Peter Zijlstra wrote:
>
>> On Sat, Feb 25, 2017 at 04:10:37PM +0800, Tan Xiaojun wrote:
>>
>>> 2)If it is, where we will fix it more appropriate, perf_fuzzer(not set
>>> 0 or 100) or kernel(limit 1 to 99), or maybe it is the bug of
>>> hardware(too many hardware interruptions)?
>>
>> I think the best would be if the fuzzer would not set 0,100, those are
>> clearly 'unsafe' settings and you pretty much get to keep the pieces.
>>
>> I would like to preserve these settings for people that 'know' what
>> they're doing and are willing to take the risk, but clearly, when you
>> take the guard-rails off, things can come apart.
>
> sorry for the delay responding, these e-mails ended up in the spam folder
> somehow.
>
> I could add a new "avoid stupid things as root" flag for the perf_fuzzer.
>
> Besides this issue, are there other known things to skip?
>
> Generally running a fuzzer as root can be a bad idea which is why I don't
> test that use case very often.
> I think there were other issues in the past, like certain ftrace
> combinations being known to lock the system.
>
> Vince
>
It would be better if you could add such a flag to the perf_fuzzer. And I
have not found any other problems yet.
By the way. Use Non-root user to test is OK, and they do not have permission
to configure these parameters.
Thank you for your reply.
Xiaojun.
> .
>
^ permalink raw reply [flat|nested] 18+ messages in thread
* [BUG arm64] OOPS when using /proc/kcore to disassemble the kernel symbols in "perf top"
2017-02-25 9:51 ` Peter Zijlstra
` (2 preceding siblings ...)
(?)
@ 2017-04-15 7:58 ` Tan Xiaojun
[not found] ` <58F1DE6A.7050307@huawei.com>
-1 siblings, 1 reply; 18+ messages in thread
From: Tan Xiaojun @ 2017-04-15 7:58 UTC (permalink / raw)
To: Peter Zijlstra
Cc: jolsa, alexander.shishkin, eranian, hpa, mingo, linux-kernel,
acme, acme, tglx, torvalds, linux-tip-commits, linux-arm-kernel,
Ding Tianhong
[-- Attachment #1: Type: text/plain, Size: 9223 bytes --]
Hi,
My test server is Hisilicon D03/D05 (arm64).
Kernel source code is 4.11-rc6 (up to date) and config (as an attachment in the end) is generated by defconfig.
When I do "perf top" and annotate a random kernel symbol (like vsnprintf or others), the system report an OOPS below:
(The probability of occurrence is very high, almost every time.)
$ perf top
Annotate vsnprintf ---- choose it
Zoom into perf(7066) thread
Zoom into the Kernel DSO
Browse map details
Run scripts for samples of thread [perf]
Run scripts for samples of symbol [vsnprintf]
Run scripts for all samples
Exit
log:
Apr 17 05:03:59 EulerOS kernel: [ 339.913498] Unable to handle kernel paging request at virtual address ffffdb16aa14028c
Apr 17 05:03:59 EulerOS kernel: [ 339.913502] pgd = ffff803f70b29000
Apr 17 05:03:59 EulerOS kernel: [ 339.913506] [ffffdb16aa14028c] *pgd=0000000000000000
Apr 17 05:03:59 EulerOS kernel: [ 339.913511] Internal error: Oops: 96000004 [#1] PREEMPT SMP
Apr 17 05:03:59 EulerOS kernel: [ 339.913514] Modules linked in:
Apr 17 05:03:59 EulerOS kernel: [ 339.913520] CPU: 6 PID: 9703 Comm: perf Not tainted 4.11.0-rc6-00029-gb9b3322 #3
Apr 17 05:03:59 EulerOS kernel: [ 339.913523] Hardware name: Huawei Taishan 2180 /BC11SPCC, BIOS 1.31 06/23/2016
Apr 17 05:03:59 EulerOS kernel: [ 339.913526] task: ffff803f6ff99a00 task.stack: ffff803f4c104000
Apr 17 05:03:59 EulerOS kernel: [ 339.913531] PC is at __memcpy+0x38/0x180
Apr 17 05:03:59 EulerOS kernel: [ 339.913535] LR is at vread+0x148/0x284
Apr 17 05:03:59 EulerOS kernel: [ 339.913538] pc : [<ffff0000083926b8>] lr : [<ffff0000081ba2a0>] pstate: 00000145
Apr 17 05:03:59 EulerOS kernel: [ 339.913540] sp : ffff803f4c107c70
Apr 17 05:03:59 EulerOS kernel: [ 339.913542] x29: ffff803f4c107c70 x28: ffff803f5ef73000
Apr 17 05:03:59 EulerOS kernel: [ 339.913548] x27: 000000000000032c x26: ffff803f6ff99a00
Apr 17 05:03:59 EulerOS kernel: [ 339.913552] x25: ffff00000839d28c x24: ffff803f7f801380
Apr 17 05:03:59 EulerOS kernel: [ 339.913557] x23: 000000000000032c x22: ffff803f5ef73000
Apr 17 05:03:59 EulerOS kernel: [ 339.913561] x21: 000000000000028c x20: ffff00000839d28c
Apr 17 05:03:59 EulerOS kernel: [ 339.913565] x19: 000000000000032c x18: 0000ffffaa6cc2d0
Apr 17 05:03:59 EulerOS kernel: [ 339.913569] x17: 0000ffffab9dc350 x16: ffff0000081f5f04
Apr 17 05:03:59 EulerOS kernel: [ 339.913573] x15: 0000317ba8000000 x14: 001c19d1d0000000
Apr 17 05:03:59 EulerOS kernel: [ 339.913577] x13: 00000003e8000000 x12: 0000000000000006
Apr 17 05:03:59 EulerOS kernel: [ 339.913581] x11: 0000000000000007 x10: 0000000000000000
Apr 17 05:03:59 EulerOS kernel: [ 339.913586] x9 : 0000000000000000 x8 : ffff000008e6d3d8
Apr 17 05:03:59 EulerOS kernel: [ 339.913590] x7 : 00005b16aa140000 x6 : ffff803f5ef73000
Apr 17 05:03:59 EulerOS kernel: [ 339.913594] x5 : 0000000000000d74 x4 : 0000000000000004
Apr 17 05:03:59 EulerOS kernel: [ 339.913598] x3 : 0000000000000000 x2 : 0000000000000328
Apr 17 05:03:59 EulerOS kernel: [ 339.913602] x1 : ffffdb16aa14028c x0 : ffff803f5ef73000
Apr 17 05:03:59 EulerOS kernel: [ 339.913606]
Apr 17 05:03:59 EulerOS kernel: [ 339.913609] Process perf (pid: 9703, stack limit = 0xffff803f4c104000)
Apr 17 05:03:59 EulerOS kernel: [ 339.913612] Stack: (0xffff803f4c107c70 to 0xffff803f4c108000)
Apr 17 05:03:59 EulerOS kernel: [ 339.913615] 7c60: ffff803f4c107d00 ffff000008267a18
Apr 17 05:03:59 EulerOS kernel: [ 339.913619] 7c80: 000000000000032c 0000000036dd9c10 ffff000008f75160 ffff803f4c107eb8
Apr 17 05:03:59 EulerOS kernel: [ 339.913622] 7ca0: 0000000000000000 ffff803f6ff99a00 ffff803f5ef73000 ffff000008e6d3d8
Apr 17 05:03:59 EulerOS kernel: [ 339.913625] 7cc0: ffff00000839d28c 000000000000032c 0000000000000024 ffff803f5ef73000
Apr 17 05:03:59 EulerOS kernel: [ 339.913629] 7ce0: 000000000000032c 000000000000032c ffff803f6ff99a00 ffff000008e684a0
Apr 17 05:03:59 EulerOS kernel: [ 339.913632] 7d00: ffff803f4c107d90 ffff000008259d00 ffff803f720c3d00 fffffffffffffffb
Apr 17 05:03:59 EulerOS kernel: [ 339.913635] 7d20: 0000000036dd9c10 ffff803f4c107eb8 0000000080000000 0000000000000015
Apr 17 05:03:59 EulerOS kernel: [ 339.913638] 7d40: 0000000000000124 000000000000003f ffff000008942000 ffff803f6ff99a00
Apr 17 05:03:59 EulerOS kernel: [ 339.913641] 7d60: ffff803f6ff08310 ffff803f6ff99a00 ffff803f6ff99a00 ffff803f6ff99a00
Apr 17 05:03:59 EulerOS kernel: [ 339.913644] 7d80: 0000000d00000124 0000000000002000 ffff803f4c107db0 ffff0000081f3810
Apr 17 05:03:59 EulerOS kernel: [ 339.913647] 7da0: ffff803f6ff08300 ffff803f4c107eb8 ffff803f4c107e30 ffff0000081f4ab0
Apr 17 05:03:59 EulerOS kernel: [ 339.913650] 7dc0: 000000000000032c ffff803f6ff08300 0000000000000000 0000000000000000
Apr 17 05:03:59 EulerOS kernel: [ 339.913653] 7de0: ffff803f4c107e10 ffff0000081f49ac ffff803f6ff08300 0000000000000000
Apr 17 05:03:59 EulerOS kernel: [ 339.913656] 7e00: 0000000036dd9c10 ffff803f4c107eb8 ffff803f4c107e30 ffff0000081f4a8c
Apr 17 05:03:59 EulerOS kernel: [ 339.913659] 7e20: 000000000000032c ffff803f6ff08300 ffff803f4c107e70 ffff0000081f5f48
Apr 17 05:03:59 EulerOS kernel: [ 339.913662] 7e40: ffff803f6ff08303 ffff803f6ff08300 ffffffffffffffff 0000ffffab9dc37c
Apr 17 05:03:59 EulerOS kernel: [ 339.913664] 7e60: 0000000000000200 0000ffffab9dcbdc 0000000000000000 ffff000008082f8c
Apr 17 05:03:59 EulerOS kernel: [ 339.913667] 7e80: 0000000000000200 0000803ff70f9000 ffffffffffffffff ffff000008082f5c
Apr 17 05:03:59 EulerOS kernel: [ 339.913670] 7ea0: 0000000036dd9c10 000000000000032c ffffffffffffffff 000000000839f28c
Apr 17 05:03:59 EulerOS kernel: [ 339.913673] 7ec0: 000000000000002a 0000000036dd9c10 000000000000032c 0000ffffaa6d42c8
Apr 17 05:03:59 EulerOS kernel: [ 339.913676] 7ee0: 0000ffffaa6cc49c 0000ffffaa6d41c0 0000ffffaa6d48b0 0000000000000000
Apr 17 05:03:59 EulerOS kernel: [ 339.913679] 7f00: 000000000000003f 0000000000000003 0000000000000020 0000000000000007
Apr 17 05:03:59 EulerOS kernel: [ 339.913682] 7f20: 0000000000000006 00000003e8000000 001c19d1d0000000 0000317ba8000000
Apr 17 05:03:59 EulerOS kernel: [ 339.913685] 7f40: 0000000000000000 0000ffffab9dc350 0000ffffaa6cc2d0 0000000000622000
Apr 17 05:03:59 EulerOS kernel: [ 339.913688] 7f60: 0000000000001000 0000000036dd9c10 000000000000032c 00000000006f1038
Apr 17 05:03:59 EulerOS kernel: [ 339.913691] 7f80: 000000000000002b 000000000000002a 000000000839f28c 0000000000000001
Apr 17 05:03:59 EulerOS kernel: [ 339.913694] 7fa0: 0000ffffaa6d3990 0000ffffaa6cc4e0 0000ffffab9dc368 0000ffffaa6cc4a0
Apr 17 05:03:59 EulerOS kernel: [ 339.913697] 7fc0: 0000ffffab9dc37c 0000000080000000 000000000000002a 000000000000003f
Apr 17 05:03:59 EulerOS kernel: [ 339.913700] 7fe0: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
Apr 17 05:03:59 EulerOS kernel: [ 339.913702] Call trace:
Apr 17 05:03:59 EulerOS kernel: [ 339.913705] Exception stack(0xffff803f4c107aa0 to 0xffff803f4c107bd0)
Apr 17 05:03:59 EulerOS kernel: [ 339.913708] 7aa0: 000000000000032c 0001000000000000 ffff803f4c107c70 ffff0000083926b8
Apr 17 05:03:59 EulerOS kernel: [ 339.913712] 7ac0: 00000000014200ca 0000000000000000 ffff803f71b1ec38 0000000000000000
Apr 17 05:03:59 EulerOS kernel: [ 339.913715] 7ae0: ffff803f6ff99a00 0000000036dda000 0000000000000000 0000000000000000
Apr 17 05:03:59 EulerOS kernel: [ 339.913718] 7b00: 000000000000000c ffff000008f6c610 ffff803f4c107b60 ffff0000082c0ae0
Apr 17 05:03:59 EulerOS kernel: [ 339.913721] 7b20: ffff803f7047a030 ffff000008f76000 0000000000000000 ffff803f7200a800
Apr 17 05:03:59 EulerOS kernel: [ 339.913724] 7b40: ffff803f5ef73000 ffffdb16aa14028c 0000000000000328 0000000000000000
Apr 17 05:03:59 EulerOS kernel: [ 339.913727] 7b60: 0000000000000004 0000000000000d74 ffff803f5ef73000 00005b16aa140000
Apr 17 05:03:59 EulerOS kernel: [ 339.913729] 7b80: ffff000008e6d3d8 0000000000000000 0000000000000000 0000000000000007
Apr 17 05:03:59 EulerOS kernel: [ 339.913732] 7ba0: 0000000000000006 00000003e8000000 001c19d1d0000000 0000317ba8000000
Apr 17 05:03:59 EulerOS kernel: [ 339.913735] 7bc0: ffff0000081f5f04 0000ffffab9dc350
Apr 17 05:03:59 EulerOS kernel: [ 339.913739] [<ffff0000083926b8>] __memcpy+0x38/0x180
Apr 17 05:03:59 EulerOS kernel: [ 339.913743] [<ffff000008267a18>] read_kcore+0x230/0x3b0
Apr 17 05:03:59 EulerOS kernel: [ 339.913747] [<ffff000008259d00>] proc_reg_read+0x64/0x90
Apr 17 05:03:59 EulerOS kernel: [ 339.913751] [<ffff0000081f3810>] __vfs_read+0x28/0x108
Apr 17 05:03:59 EulerOS kernel: [ 339.913754] [<ffff0000081f4ab0>] vfs_read+0x80/0x13c
Apr 17 05:03:59 EulerOS kernel: [ 339.913757] [<ffff0000081f5f48>] SyS_read+0x44/0xa0
Apr 17 05:03:59 EulerOS kernel: [ 339.913761] [<ffff000008082f8c>] __sys_trace_return+0x0/0x4
Apr 17 05:03:59 EulerOS kernel: [ 339.913765] Code: 36080064 78402423 780024c3 36100064 (b8404423)
Apr 17 05:03:59 EulerOS kernel: [ 339.913768] ---[ end trace 6710f03ffe50aedc ]---
Apr 17 05:03:59 EulerOS kernel: [ 339.913772] note: perf[9703] exited with preempt_count 2
Call relationship:
read_kcore -> vread -> aligned_vread -> memcpy -> __memcpy
Maybe you can give me some ideas.
Thanks a lot.
Xiaojun.
[-- Attachment #2: .config --]
[-- Type: application/xml, Size: 150271 bytes --]
^ permalink raw reply [flat|nested] 18+ messages in thread
* [arm64] OOPS when using /proc/kcore to disassemble the kernel symbols in "perf top"
[not found] ` <58F1DE6A.7050307@huawei.com>
@ 2017-04-19 4:14 ` Pratyush Anand
2017-04-19 8:01 ` Tan Xiaojun
2017-04-19 11:49 ` Mark Rutland
0 siblings, 2 replies; 18+ messages in thread
From: Pratyush Anand @ 2017-04-19 4:14 UTC (permalink / raw)
To: linux-arm-kernel
Hi tan,
On Saturday 15 April 2017 02:18 PM, Tan Xiaojun wrote:
> Hi,
>
> My test server is Hisilicon D03/D05 (arm64).
> Kernel source code is 4.11-rc6 (up to date) and config (as an attachment in the end) is generated by defconfig.
> (Old version does not seem to have this problem. Linux-4.1 is fine and other versions I have not tested yet.)
I tested with mustang(ARM64) and 4.11-rc6 and could not reproduce it.
>
> When I do "perf top" and annotate a random kernel symbol (like vsnprintf or others), the system report an OOPS below:
> (The probability of occurrence is very high, almost every time.)
>
> $ perf top
>
> Annotate vsnprintf ---- choose it
> Zoom into perf(7066) thread
> Zoom into the Kernel DSO
> Browse map details
> Run scripts for samples of thread [perf]
> Run scripts for samples of symbol [vsnprintf]
> Run scripts for all samples
> Exit
>
> log:
> Apr 17 05:03:59 EulerOS kernel: [ 339.913498] Unable to handle kernel paging request at virtual address ffffdb16aa14028c
> Apr 17 05:03:59 EulerOS kernel: [ 339.913502] pgd = ffff803f70b29000
> Apr 17 05:03:59 EulerOS kernel: [ 339.913506] [ffffdb16aa14028c] *pgd=0000000000000000
> Apr 17 05:03:59 EulerOS kernel: [ 339.913511] Internal error: Oops: 96000004 [#1] PREEMPT SMP
> Apr 17 05:03:59 EulerOS kernel: [ 339.913514] Modules linked in:
> Apr 17 05:03:59 EulerOS kernel: [ 339.913520] CPU: 6 PID: 9703 Comm: perf Not tainted 4.11.0-rc6-00029-gb9b3322 #3
> Apr 17 05:03:59 EulerOS kernel: [ 339.913523] Hardware name: Huawei Taishan 2180 /BC11SPCC, BIOS 1.31 06/23/2016
> Apr 17 05:03:59 EulerOS kernel: [ 339.913526] task: ffff803f6ff99a00 task.stack: ffff803f4c104000
> Apr 17 05:03:59 EulerOS kernel: [ 339.913531] PC is at __memcpy+0x38/0x180
> Apr 17 05:03:59 EulerOS kernel: [ 339.913535] LR is at vread+0x148/0x284
> Apr 17 05:03:59 EulerOS kernel: [ 339.913538] pc : [<ffff0000083926b8>] lr : [<ffff0000081ba2a0>] pstate: 00000145
> Apr 17 05:03:59 EulerOS kernel: [ 339.913540] sp : ffff803f4c107c70
> Apr 17 05:03:59 EulerOS kernel: [ 339.913542] x29: ffff803f4c107c70 x28: ffff803f5ef73000
> Apr 17 05:03:59 EulerOS kernel: [ 339.913548] x27: 000000000000032c x26: ffff803f6ff99a00
> Apr 17 05:03:59 EulerOS kernel: [ 339.913552] x25: ffff00000839d28c x24: ffff803f7f801380
> Apr 17 05:03:59 EulerOS kernel: [ 339.913557] x23: 000000000000032c x22: ffff803f5ef73000
> Apr 17 05:03:59 EulerOS kernel: [ 339.913561] x21: 000000000000028c x20: ffff00000839d28c
> Apr 17 05:03:59 EulerOS kernel: [ 339.913565] x19: 000000000000032c x18: 0000ffffaa6cc2d0
> Apr 17 05:03:59 EulerOS kernel: [ 339.913569] x17: 0000ffffab9dc350 x16: ffff0000081f5f04
> Apr 17 05:03:59 EulerOS kernel: [ 339.913573] x15: 0000317ba8000000 x14: 001c19d1d0000000
> Apr 17 05:03:59 EulerOS kernel: [ 339.913577] x13: 00000003e8000000 x12: 0000000000000006
> Apr 17 05:03:59 EulerOS kernel: [ 339.913581] x11: 0000000000000007 x10: 0000000000000000
> Apr 17 05:03:59 EulerOS kernel: [ 339.913586] x9 : 0000000000000000 x8 : ffff000008e6d3d8
> Apr 17 05:03:59 EulerOS kernel: [ 339.913590] x7 : 00005b16aa140000 x6 : ffff803f5ef73000
> Apr 17 05:03:59 EulerOS kernel: [ 339.913594] x5 : 0000000000000d74 x4 : 0000000000000004
> Apr 17 05:03:59 EulerOS kernel: [ 339.913598] x3 : 0000000000000000 x2 : 0000000000000328
> Apr 17 05:03:59 EulerOS kernel: [ 339.913602] x1 : ffffdb16aa14028c x0 : ffff803f5ef73000
So, source pointer for the memcpy(2nd arg) seems wrong. (Unable to handle
kernel paging request at virtual address ffffdb16aa14028c, and x1 is
ffffdb16aa14028c).
I tried to look into code around source pointer,and they seem to be correct.
in read_kcore(): start is source pointer.
start = kc_offset_to_vaddr(*fpos - elf_buflen);
vread(buf, (char *)start, tsz);
in vread() -> aligned_vread(): addr is source pointer.
offset = offset_in_page(addr);
p = vmalloc_to_page(addr);
*map = kmap_atomic(p);
memcpy(buf, map + offset, length);
They all look fine and should work. Since, it always works with 4.1 on your
platform, can you please try a git bisect to see which commit is causing
trouble for you.
~Pratyush
> Apr 17 05:03:59 EulerOS kernel: [ 339.913606]
> Apr 17 05:03:59 EulerOS kernel: [ 339.913609] Process perf (pid: 9703, stack limit = 0xffff803f4c104000)
> Apr 17 05:03:59 EulerOS kernel: [ 339.913612] Stack: (0xffff803f4c107c70 to 0xffff803f4c108000)
> Apr 17 05:03:59 EulerOS kernel: [ 339.913615] 7c60: ffff803f4c107d00 ffff000008267a18
> Apr 17 05:03:59 EulerOS kernel: [ 339.913619] 7c80: 000000000000032c 0000000036dd9c10 ffff000008f75160 ffff803f4c107eb8
> Apr 17 05:03:59 EulerOS kernel: [ 339.913622] 7ca0: 0000000000000000 ffff803f6ff99a00 ffff803f5ef73000 ffff000008e6d3d8
> Apr 17 05:03:59 EulerOS kernel: [ 339.913625] 7cc0: ffff00000839d28c 000000000000032c 0000000000000024 ffff803f5ef73000
> Apr 17 05:03:59 EulerOS kernel: [ 339.913629] 7ce0: 000000000000032c 000000000000032c ffff803f6ff99a00 ffff000008e684a0
> Apr 17 05:03:59 EulerOS kernel: [ 339.913632] 7d00: ffff803f4c107d90 ffff000008259d00 ffff803f720c3d00 fffffffffffffffb
> Apr 17 05:03:59 EulerOS kernel: [ 339.913635] 7d20: 0000000036dd9c10 ffff803f4c107eb8 0000000080000000 0000000000000015
> Apr 17 05:03:59 EulerOS kernel: [ 339.913638] 7d40: 0000000000000124 000000000000003f ffff000008942000 ffff803f6ff99a00
> Apr 17 05:03:59 EulerOS kernel: [ 339.913641] 7d60: ffff803f6ff08310 ffff803f6ff99a00 ffff803f6ff99a00 ffff803f6ff99a00
> Apr 17 05:03:59 EulerOS kernel: [ 339.913644] 7d80: 0000000d00000124 0000000000002000 ffff803f4c107db0 ffff0000081f3810
> Apr 17 05:03:59 EulerOS kernel: [ 339.913647] 7da0: ffff803f6ff08300 ffff803f4c107eb8 ffff803f4c107e30 ffff0000081f4ab0
> Apr 17 05:03:59 EulerOS kernel: [ 339.913650] 7dc0: 000000000000032c ffff803f6ff08300 0000000000000000 0000000000000000
> Apr 17 05:03:59 EulerOS kernel: [ 339.913653] 7de0: ffff803f4c107e10 ffff0000081f49ac ffff803f6ff08300 0000000000000000
> Apr 17 05:03:59 EulerOS kernel: [ 339.913656] 7e00: 0000000036dd9c10 ffff803f4c107eb8 ffff803f4c107e30 ffff0000081f4a8c
> Apr 17 05:03:59 EulerOS kernel: [ 339.913659] 7e20: 000000000000032c ffff803f6ff08300 ffff803f4c107e70 ffff0000081f5f48
> Apr 17 05:03:59 EulerOS kernel: [ 339.913662] 7e40: ffff803f6ff08303 ffff803f6ff08300 ffffffffffffffff 0000ffffab9dc37c
> Apr 17 05:03:59 EulerOS kernel: [ 339.913664] 7e60: 0000000000000200 0000ffffab9dcbdc 0000000000000000 ffff000008082f8c
> Apr 17 05:03:59 EulerOS kernel: [ 339.913667] 7e80: 0000000000000200 0000803ff70f9000 ffffffffffffffff ffff000008082f5c
> Apr 17 05:03:59 EulerOS kernel: [ 339.913670] 7ea0: 0000000036dd9c10 000000000000032c ffffffffffffffff 000000000839f28c
> Apr 17 05:03:59 EulerOS kernel: [ 339.913673] 7ec0: 000000000000002a 0000000036dd9c10 000000000000032c 0000ffffaa6d42c8
> Apr 17 05:03:59 EulerOS kernel: [ 339.913676] 7ee0: 0000ffffaa6cc49c 0000ffffaa6d41c0 0000ffffaa6d48b0 0000000000000000
> Apr 17 05:03:59 EulerOS kernel: [ 339.913679] 7f00: 000000000000003f 0000000000000003 0000000000000020 0000000000000007
> Apr 17 05:03:59 EulerOS kernel: [ 339.913682] 7f20: 0000000000000006 00000003e8000000 001c19d1d0000000 0000317ba8000000
> Apr 17 05:03:59 EulerOS kernel: [ 339.913685] 7f40: 0000000000000000 0000ffffab9dc350 0000ffffaa6cc2d0 0000000000622000
> Apr 17 05:03:59 EulerOS kernel: [ 339.913688] 7f60: 0000000000001000 0000000036dd9c10 000000000000032c 00000000006f1038
> Apr 17 05:03:59 EulerOS kernel: [ 339.913691] 7f80: 000000000000002b 000000000000002a 000000000839f28c 0000000000000001
> Apr 17 05:03:59 EulerOS kernel: [ 339.913694] 7fa0: 0000ffffaa6d3990 0000ffffaa6cc4e0 0000ffffab9dc368 0000ffffaa6cc4a0
> Apr 17 05:03:59 EulerOS kernel: [ 339.913697] 7fc0: 0000ffffab9dc37c 0000000080000000 000000000000002a 000000000000003f
> Apr 17 05:03:59 EulerOS kernel: [ 339.913700] 7fe0: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
> Apr 17 05:03:59 EulerOS kernel: [ 339.913702] Call trace:
> Apr 17 05:03:59 EulerOS kernel: [ 339.913705] Exception stack(0xffff803f4c107aa0 to 0xffff803f4c107bd0)
> Apr 17 05:03:59 EulerOS kernel: [ 339.913708] 7aa0: 000000000000032c 0001000000000000 ffff803f4c107c70 ffff0000083926b8
> Apr 17 05:03:59 EulerOS kernel: [ 339.913712] 7ac0: 00000000014200ca 0000000000000000 ffff803f71b1ec38 0000000000000000
> Apr 17 05:03:59 EulerOS kernel: [ 339.913715] 7ae0: ffff803f6ff99a00 0000000036dda000 0000000000000000 0000000000000000
> Apr 17 05:03:59 EulerOS kernel: [ 339.913718] 7b00: 000000000000000c ffff000008f6c610 ffff803f4c107b60 ffff0000082c0ae0
> Apr 17 05:03:59 EulerOS kernel: [ 339.913721] 7b20: ffff803f7047a030 ffff000008f76000 0000000000000000 ffff803f7200a800
> Apr 17 05:03:59 EulerOS kernel: [ 339.913724] 7b40: ffff803f5ef73000 ffffdb16aa14028c 0000000000000328 0000000000000000
> Apr 17 05:03:59 EulerOS kernel: [ 339.913727] 7b60: 0000000000000004 0000000000000d74 ffff803f5ef73000 00005b16aa140000
> Apr 17 05:03:59 EulerOS kernel: [ 339.913729] 7b80: ffff000008e6d3d8 0000000000000000 0000000000000000 0000000000000007
> Apr 17 05:03:59 EulerOS kernel: [ 339.913732] 7ba0: 0000000000000006 00000003e8000000 001c19d1d0000000 0000317ba8000000
> Apr 17 05:03:59 EulerOS kernel: [ 339.913735] 7bc0: ffff0000081f5f04 0000ffffab9dc350
> Apr 17 05:03:59 EulerOS kernel: [ 339.913739] [<ffff0000083926b8>] __memcpy+0x38/0x180
> Apr 17 05:03:59 EulerOS kernel: [ 339.913743] [<ffff000008267a18>] read_kcore+0x230/0x3b0
> Apr 17 05:03:59 EulerOS kernel: [ 339.913747] [<ffff000008259d00>] proc_reg_read+0x64/0x90
> Apr 17 05:03:59 EulerOS kernel: [ 339.913751] [<ffff0000081f3810>] __vfs_read+0x28/0x108
> Apr 17 05:03:59 EulerOS kernel: [ 339.913754] [<ffff0000081f4ab0>] vfs_read+0x80/0x13c
> Apr 17 05:03:59 EulerOS kernel: [ 339.913757] [<ffff0000081f5f48>] SyS_read+0x44/0xa0
> Apr 17 05:03:59 EulerOS kernel: [ 339.913761] [<ffff000008082f8c>] __sys_trace_return+0x0/0x4
> Apr 17 05:03:59 EulerOS kernel: [ 339.913765] Code: 36080064 78402423 780024c3 36100064 (b8404423)
> Apr 17 05:03:59 EulerOS kernel: [ 339.913768] ---[ end trace 6710f03ffe50aedc ]---
> Apr 17 05:03:59 EulerOS kernel: [ 339.913772] note: perf[9703] exited with preempt_count 2
>
> Call relationship:
> read_kcore -> vread -> aligned_vread -> memcpy -> __memcpy
>
> Maybe you can give me some ideas.
>
> Thanks a lot.
>
> Xiaojun.
>
>
>
>
^ permalink raw reply [flat|nested] 18+ messages in thread
* [arm64] OOPS when using /proc/kcore to disassemble the kernel symbols in "perf top"
2017-04-19 4:14 ` [arm64] " Pratyush Anand
@ 2017-04-19 8:01 ` Tan Xiaojun
2017-04-19 11:49 ` Mark Rutland
1 sibling, 0 replies; 18+ messages in thread
From: Tan Xiaojun @ 2017-04-19 8:01 UTC (permalink / raw)
To: linux-arm-kernel
On 2017/4/19 12:14, Pratyush Anand wrote:
> Hi tan,
>
> On Saturday 15 April 2017 02:18 PM, Tan Xiaojun wrote:
>> Hi,
>>
>> My test server is Hisilicon D03/D05 (arm64).
>> Kernel source code is 4.11-rc6 (up to date) and config (as an attachment in the end) is generated by defconfig.
>> (Old version does not seem to have this problem. Linux-4.1 is fine and other versions I have not tested yet.)
>
> I tested with mustang(ARM64) and 4.11-rc6 and could not reproduce it.
>
This is important. Thanks a lot.
>>
>> When I do "perf top" and annotate a random kernel symbol (like vsnprintf or others), the system report an OOPS below:
>> (The probability of occurrence is very high, almost every time.)
>>
>> $ perf top
>>
>> Annotate vsnprintf ---- choose it
>> Zoom into perf(7066) thread
>> Zoom into the Kernel DSO
>> Browse map details
>> Run scripts for samples of thread [perf]
>> Run scripts for samples of symbol [vsnprintf]
>> Run scripts for all samples
>> Exit
>>
>> log:
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913498] Unable to handle kernel paging request at virtual address ffffdb16aa14028c
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913502] pgd = ffff803f70b29000
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913506] [ffffdb16aa14028c] *pgd=0000000000000000
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913511] Internal error: Oops: 96000004 [#1] PREEMPT SMP
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913514] Modules linked in:
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913520] CPU: 6 PID: 9703 Comm: perf Not tainted 4.11.0-rc6-00029-gb9b3322 #3
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913523] Hardware name: Huawei Taishan 2180 /BC11SPCC, BIOS 1.31 06/23/2016
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913526] task: ffff803f6ff99a00 task.stack: ffff803f4c104000
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913531] PC is at __memcpy+0x38/0x180
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913535] LR is at vread+0x148/0x284
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913538] pc : [<ffff0000083926b8>] lr : [<ffff0000081ba2a0>] pstate: 00000145
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913540] sp : ffff803f4c107c70
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913542] x29: ffff803f4c107c70 x28: ffff803f5ef73000
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913548] x27: 000000000000032c x26: ffff803f6ff99a00
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913552] x25: ffff00000839d28c x24: ffff803f7f801380
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913557] x23: 000000000000032c x22: ffff803f5ef73000
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913561] x21: 000000000000028c x20: ffff00000839d28c
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913565] x19: 000000000000032c x18: 0000ffffaa6cc2d0
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913569] x17: 0000ffffab9dc350 x16: ffff0000081f5f04
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913573] x15: 0000317ba8000000 x14: 001c19d1d0000000
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913577] x13: 00000003e8000000 x12: 0000000000000006
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913581] x11: 0000000000000007 x10: 0000000000000000
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913586] x9 : 0000000000000000 x8 : ffff000008e6d3d8
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913590] x7 : 00005b16aa140000 x6 : ffff803f5ef73000
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913594] x5 : 0000000000000d74 x4 : 0000000000000004
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913598] x3 : 0000000000000000 x2 : 0000000000000328
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913602] x1 : ffffdb16aa14028c x0 : ffff803f5ef73000
>
> So, source pointer for the memcpy(2nd arg) seems wrong. (Unable to handle kernel paging request at virtual address ffffdb16aa14028c, and x1 is ffffdb16aa14028c).
>
> I tried to look into code around source pointer,and they seem to be correct.
>
> in read_kcore(): start is source pointer.
> start = kc_offset_to_vaddr(*fpos - elf_buflen);
> vread(buf, (char *)start, tsz);
>
> in vread() -> aligned_vread(): addr is source pointer.
> offset = offset_in_page(addr);
> p = vmalloc_to_page(addr);
> *map = kmap_atomic(p);
> memcpy(buf, map + offset, length);
>
> They all look fine and should work. Since, it always works with 4.1 on your platform, can you please try a git bisect to see which commit is causing trouble for you.
>
> ~Pratyush
>
Yes, Pratyush, you are right. I am working on it now.
Thank you for your reply.
Xiaojun.
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913606]
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913609] Process perf (pid: 9703, stack limit = 0xffff803f4c104000)
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913612] Stack: (0xffff803f4c107c70 to 0xffff803f4c108000)
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913615] 7c60: ffff803f4c107d00 ffff000008267a18
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913619] 7c80: 000000000000032c 0000000036dd9c10 ffff000008f75160 ffff803f4c107eb8
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913622] 7ca0: 0000000000000000 ffff803f6ff99a00 ffff803f5ef73000 ffff000008e6d3d8
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913625] 7cc0: ffff00000839d28c 000000000000032c 0000000000000024 ffff803f5ef73000
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913629] 7ce0: 000000000000032c 000000000000032c ffff803f6ff99a00 ffff000008e684a0
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913632] 7d00: ffff803f4c107d90 ffff000008259d00 ffff803f720c3d00 fffffffffffffffb
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913635] 7d20: 0000000036dd9c10 ffff803f4c107eb8 0000000080000000 0000000000000015
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913638] 7d40: 0000000000000124 000000000000003f ffff000008942000 ffff803f6ff99a00
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913641] 7d60: ffff803f6ff08310 ffff803f6ff99a00 ffff803f6ff99a00 ffff803f6ff99a00
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913644] 7d80: 0000000d00000124 0000000000002000 ffff803f4c107db0 ffff0000081f3810
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913647] 7da0: ffff803f6ff08300 ffff803f4c107eb8 ffff803f4c107e30 ffff0000081f4ab0
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913650] 7dc0: 000000000000032c ffff803f6ff08300 0000000000000000 0000000000000000
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913653] 7de0: ffff803f4c107e10 ffff0000081f49ac ffff803f6ff08300 0000000000000000
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913656] 7e00: 0000000036dd9c10 ffff803f4c107eb8 ffff803f4c107e30 ffff0000081f4a8c
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913659] 7e20: 000000000000032c ffff803f6ff08300 ffff803f4c107e70 ffff0000081f5f48
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913662] 7e40: ffff803f6ff08303 ffff803f6ff08300 ffffffffffffffff 0000ffffab9dc37c
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913664] 7e60: 0000000000000200 0000ffffab9dcbdc 0000000000000000 ffff000008082f8c
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913667] 7e80: 0000000000000200 0000803ff70f9000 ffffffffffffffff ffff000008082f5c
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913670] 7ea0: 0000000036dd9c10 000000000000032c ffffffffffffffff 000000000839f28c
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913673] 7ec0: 000000000000002a 0000000036dd9c10 000000000000032c 0000ffffaa6d42c8
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913676] 7ee0: 0000ffffaa6cc49c 0000ffffaa6d41c0 0000ffffaa6d48b0 0000000000000000
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913679] 7f00: 000000000000003f 0000000000000003 0000000000000020 0000000000000007
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913682] 7f20: 0000000000000006 00000003e8000000 001c19d1d0000000 0000317ba8000000
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913685] 7f40: 0000000000000000 0000ffffab9dc350 0000ffffaa6cc2d0 0000000000622000
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913688] 7f60: 0000000000001000 0000000036dd9c10 000000000000032c 00000000006f1038
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913691] 7f80: 000000000000002b 000000000000002a 000000000839f28c 0000000000000001
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913694] 7fa0: 0000ffffaa6d3990 0000ffffaa6cc4e0 0000ffffab9dc368 0000ffffaa6cc4a0
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913697] 7fc0: 0000ffffab9dc37c 0000000080000000 000000000000002a 000000000000003f
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913700] 7fe0: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913702] Call trace:
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913705] Exception stack(0xffff803f4c107aa0 to 0xffff803f4c107bd0)
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913708] 7aa0: 000000000000032c 0001000000000000 ffff803f4c107c70 ffff0000083926b8
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913712] 7ac0: 00000000014200ca 0000000000000000 ffff803f71b1ec38 0000000000000000
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913715] 7ae0: ffff803f6ff99a00 0000000036dda000 0000000000000000 0000000000000000
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913718] 7b00: 000000000000000c ffff000008f6c610 ffff803f4c107b60 ffff0000082c0ae0
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913721] 7b20: ffff803f7047a030 ffff000008f76000 0000000000000000 ffff803f7200a800
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913724] 7b40: ffff803f5ef73000 ffffdb16aa14028c 0000000000000328 0000000000000000
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913727] 7b60: 0000000000000004 0000000000000d74 ffff803f5ef73000 00005b16aa140000
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913729] 7b80: ffff000008e6d3d8 0000000000000000 0000000000000000 0000000000000007
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913732] 7ba0: 0000000000000006 00000003e8000000 001c19d1d0000000 0000317ba8000000
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913735] 7bc0: ffff0000081f5f04 0000ffffab9dc350
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913739] [<ffff0000083926b8>] __memcpy+0x38/0x180
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913743] [<ffff000008267a18>] read_kcore+0x230/0x3b0
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913747] [<ffff000008259d00>] proc_reg_read+0x64/0x90
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913751] [<ffff0000081f3810>] __vfs_read+0x28/0x108
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913754] [<ffff0000081f4ab0>] vfs_read+0x80/0x13c
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913757] [<ffff0000081f5f48>] SyS_read+0x44/0xa0
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913761] [<ffff000008082f8c>] __sys_trace_return+0x0/0x4
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913765] Code: 36080064 78402423 780024c3 36100064 (b8404423)
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913768] ---[ end trace 6710f03ffe50aedc ]---
>> Apr 17 05:03:59 EulerOS kernel: [ 339.913772] note: perf[9703] exited with preempt_count 2
>>
>> Call relationship:
>> read_kcore -> vread -> aligned_vread -> memcpy -> __memcpy
>>
>> Maybe you can give me some ideas.
>>
>> Thanks a lot.
>>
>> Xiaojun.
>>
>>
>>
>>
>
> .
>
^ permalink raw reply [flat|nested] 18+ messages in thread
* [arm64] OOPS when using /proc/kcore to disassemble the kernel symbols in "perf top"
2017-04-19 4:14 ` [arm64] " Pratyush Anand
2017-04-19 8:01 ` Tan Xiaojun
@ 2017-04-19 11:49 ` Mark Rutland
2017-04-20 1:38 ` Tan Xiaojun
1 sibling, 1 reply; 18+ messages in thread
From: Mark Rutland @ 2017-04-19 11:49 UTC (permalink / raw)
To: linux-arm-kernel
Hi,
Ard, this sseems to be a nomap issue. Please see below.
Xiaojun, for some reason, the first message in this thread didn't seem
to make it to LAKML (or to me). In future could you please Cc me for
emails regarding perf on arm/arm64?
On Wed, Apr 19, 2017 at 09:44:56AM +0530, Pratyush Anand wrote:
> On Saturday 15 April 2017 02:18 PM, Tan Xiaojun wrote:
> >My test server is Hisilicon D03/D05 (arm64).
> >Kernel source code is 4.11-rc6 (up to date) and config (as an attachment in the end) is generated by defconfig.
> >(Old version does not seem to have this problem. Linux-4.1 is fine and other versions I have not tested yet.)
>
> I tested with mustang(ARM64) and 4.11-rc6 and could not reproduce it.
>
> >When I do "perf top" and annotate a random kernel symbol (like vsnprintf or others), the system report an OOPS below:
> >(The probability of occurrence is very high, almost every time.)
> >
> >$ perf top
> >
> >Annotate vsnprintf ---- choose it
> >Zoom into perf(7066) thread
> >Zoom into the Kernel DSO
> >Browse map details
> >Run scripts for samples of thread [perf]
> >Run scripts for samples of symbol [vsnprintf]
> >Run scripts for all samples
> >Exit
Was perf built from the same v4.11-rc6 source tree, or was this an older
perf binary?
With a perf tool built from v4.11-rc6, even with CAP_SYS_RAWIO, I see perf top
complaining that it it cannot annotate the symbol due to a lack of a vmlinux
file. I can't seem to convince it to use /proc/kcore.
However, I can reproduce the issue by other means:
# cat /proc/kcore > /dev/null
[ 4544.984139] Unable to handle kernel paging request at virtual address ffff804392800000
[ 4544.991995] pgd = ffff80096745f000
[ 4544.995369] [ffff804392800000] *pgd=0000000000000000
[ 4545.000297] Internal error: Oops: 96000005 [#1] PREEMPT SMP
[ 4545.005815] Modules linked in:
[ 4545.008843] CPU: 1 PID: 8976 Comm: cat Not tainted 4.11.0-rc6 #1
[ 4545.014790] Hardware name: ARM Juno development board (r1) (DT)
[ 4545.020653] task: ffff8009753fdb00 task.stack: ffff80097533c000
[ 4545.026520] PC is at __memcpy+0x100/0x180
[ 4545.030491] LR is at vread+0x144/0x280
[ 4545.034202] pc : [<ffff0000083a1000>] lr : [<ffff0000081c126c>] pstate: 20000145
[ 4545.041530] sp : ffff80097533fcb0
[ 4545.044811] x29: ffff80097533fcb0 x28: ffff800962d24000
[ 4545.050074] x27: 0000000000001000 x26: ffff8009753fdb00
[ 4545.055337] x25: ffff000008200000 x24: ffff800977801380
[ 4545.060600] x23: ffff8009753fdb00 x22: ffff800962d24000
[ 4545.065863] x21: 0000000000001000 x20: ffff000008200000
[ 4545.071125] x19: 0000000000001000 x18: 0000ffffefa323c0
[ 4545.076387] x17: 0000ffffa9c87440 x16: ffff0000081fdfd0
[ 4545.081649] x15: 0000ffffa9d01588 x14: 72a77346b2407be7
[ 4545.086911] x13: 5299400690000000 x12: b0000001f9001a79
[ 4545.092173] x11: 97fc098d91042260 x10: 0000000000000000
[ 4545.097435] x9 : 0000000000000000 x8 : 9110626091260021
[ 4545.102698] x7 : 0000000000001000 x6 : ffff800962d24000
[ 4545.107960] x5 : ffff8009778013b0 x4 : 0000000000000000
[ 4545.113222] x3 : 0400000000000001 x2 : 0000000000000f80
[ 4545.118484] x1 : ffff804392800000 x0 : ffff800962d24000
[ 4545.123745]
[ 4545.125220] Process cat (pid: 8976, stack limit = 0xffff80097533c000)
[ 4545.131598] Stack: (0xffff80097533fcb0 to 0xffff800975340000)
[ 4545.137289] fca0: ffff80097533fd30 ffff000008270f64
[ 4545.145049] fcc0: 000000000000e000 000000003956f000 ffff000008f950d0 ffff80097533feb8
[ 4545.152809] fce0: 0000000000002000 ffff8009753fdb00 ffff800962d24000 ffff000008e8d3d8
[ 4545.160568] fd00: 0000000000001000 ffff000008200000 0000000000001000 ffff800962d24000
[ 4545.168327] fd20: 0000000000001000 ffff000008e884a0 ffff80097533fdb0 ffff00000826340c
[ 4545.176086] fd40: ffff800976bf2800 fffffffffffffffb 000000003956d000 ffff80097533feb8
[ 4545.183846] fd60: 0000000060000000 0000000000000015 0000000000000124 000000000000003f
[ 4545.191605] fd80: ffff000008962000 ffff8009753fdb00 ffff8009753fdb00 ffff8009753fdb00
[ 4545.199364] fda0: 0000000300000124 0000000000002000 ffff80097533fdd0 ffff0000081fb83c
[ 4545.207123] fdc0: 0000000000010000 ffff80097514f900 ffff80097533fe50 ffff0000081fcb28
[ 4545.214883] fde0: 0000000000010000 ffff80097514f900 0000000000000000 0000000000000000
[ 4545.222642] fe00: ffff80097533fe30 ffff0000081fca1c ffff80097514f900 0000000000000000
[ 4545.230401] fe20: 000000003956d000 ffff80097533feb8 ffff80097533fe50 ffff0000081fcb04
[ 4545.238160] fe40: 0000000000010000 ffff80097514f900 ffff80097533fe80 ffff0000081fe014
[ 4545.245919] fe60: ffff80097514f900 ffff80097514f900 000000003956d000 0000000000010000
[ 4545.253678] fe80: 0000000000000000 ffff000008082f30 0000000000000000 0000800977146000
[ 4545.261438] fea0: ffffffffffffffff 0000ffffa9c8745c 0000000000000124 0000000008202000
[ 4545.269197] fec0: 0000000000000003 000000003956d000 0000000000010000 0000000000000000
[ 4545.276956] fee0: 0000000000011011 0000000000000001 0000000000000011 0000000000000002
[ 4545.284715] ff00: 000000000000003f 1f3c201f7372686b 00000000ffffffff 0000000000000030
[ 4545.292474] ff20: 0000000000000038 0000000000000000 0000ffffa9bcca94 0000ffffa9d01588
[ 4545.300233] ff40: 0000000000000000 0000ffffa9c87440 0000ffffefa323c0 0000000000010000
[ 4545.307993] ff60: 000000000041a310 000000003956d000 0000000000000003 000000007fffe000
[ 4545.315751] ff80: 00000000004088d0 0000000000010000 0000000000000000 0000000000000000
[ 4545.323511] ffa0: 0000000000010000 0000ffffefa32690 0000000000404dcc 0000ffffefa32690
[ 4545.331270] ffc0: 0000ffffa9c8745c 0000000060000000 0000000000000003 000000000000003f
[ 4545.339029] ffe0: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
[ 4545.346786] Call trace:
[ 4545.349207] Exception stack(0xffff80097533fae0 to 0xffff80097533fc10)
[ 4545.355586] fae0: 0000000000001000 0001000000000000 ffff80097533fcb0 ffff0000083a1000
[ 4545.363345] fb00: 000000003957c000 ffff80097533fc00 0000000020000145 0000000000000025
[ 4545.371105] fb20: ffff800962d24000 ffff000008e8d3d8 0000000000001000 ffff8009753fdb00
[ 4545.378864] fb40: 0000000000000000 0000000000000002 ffff80097533fd30 ffff000008082604
[ 4545.386623] fb60: 0000000000001000 0001000000000000 ffff80097533fd30 ffff0000083a0a90
[ 4545.394382] fb80: ffff800962d24000 ffff804392800000 0000000000000f80 0400000000000001
[ 4545.402140] fba0: 0000000000000000 ffff8009778013b0 ffff800962d24000 0000000000001000
[ 4545.409899] fbc0: 9110626091260021 0000000000000000 0000000000000000 97fc098d91042260
[ 4545.417658] fbe0: b0000001f9001a79 5299400690000000 72a77346b2407be7 0000ffffa9d01588
[ 4545.425416] fc00: ffff0000081fdfd0 0000ffffa9c87440
[ 4545.430248] [<ffff0000083a1000>] __memcpy+0x100/0x180
[ 4545.435253] [<ffff000008270f64>] read_kcore+0x21c/0x3b0
[ 4545.440429] [<ffff00000826340c>] proc_reg_read+0x64/0x90
[ 4545.445691] [<ffff0000081fb83c>] __vfs_read+0x1c/0x108
[ 4545.450779] [<ffff0000081fcb28>] vfs_read+0x80/0x130
[ 4545.455696] [<ffff0000081fe014>] SyS_read+0x44/0xa0
[ 4545.460528] [<ffff000008082f30>] el0_svc_naked+0x24/0x28
[ 4545.465790] Code: d503201f d503201f d503201f d503201f (a8c12027)
[ 4545.471852] ---[ end trace 4d1897f94759f461 ]---
[ 4545.476435] note: cat[8976] exited with preempt_count 2
So the call flow is:
read_core() // finds the address is vmalloc or module
-> vread()
--> aligned_vread()
In aligned_vread(), we vmalloc_to_page() the address, and find a page.
We then try to kmap_atomic() that. The generic kmap_atomic() returns the
linear map alias of the address.
However, it appears that the page is nomap'd memory, and the linear
alias doesn't exist. Thus memcpy explodes when trying to access that
address.
I've verified that with:
----
diff --git a/mm/vmalloc.c b/mm/vmalloc.c
index 0b05762..d7f48e0 100644
--- a/mm/vmalloc.c
+++ b/mm/vmalloc.c
@@ -9,6 +9,7 @@
*/
#include <linux/vmalloc.h>
+#include <linux/memblock.h>
#include <linux/mm.h>
#include <linux/module.h>
#include <linux/highmem.h>
@@ -1978,6 +1979,8 @@ static int aligned_vread(char *buf, char *addr, unsigned long count)
{
struct page *p;
int copied = 0;
+ phys_addr_t phys;
+ bool nomap;
while (count) {
unsigned long offset, length;
@@ -2000,6 +2003,14 @@ static int aligned_vread(char *buf, char *addr, unsigned long count)
* function description)
*/
void *map = kmap_atomic(p);
+
+ phys = page_to_phys(p);
+ nomap = !memblock_is_map_memory(phys);
+
+ pr_info("HARK: %s kmap'd %pa (%s memory) @ %p\n",
+ __func__, &phys, (nomap ? "nomap" : "map"),
+ map);
+
memcpy(buf, map + offset, length);
kunmap_atomic(map);
} else
----
# cat /proc/kcore > /dev/null
... which eventually results in:
[ 47.360980] HARK: aligned_vread kmap'd 0x000003e290005000 (nomap memory) @ ffff83e210005000
[ 47.369297] Unable to handle kernel paging request at virtual address ffff83e210005000
I'm not sure what we should do here.
I'm not immediately sure what the nomap region is. I'm using UEFI && DT,
so I guess it's not ACPI tables.
I can try to dump more info later.
Thanks,
Mark.
^ permalink raw reply related [flat|nested] 18+ messages in thread
* [arm64] OOPS when using /proc/kcore to disassemble the kernel symbols in "perf top"
2017-04-19 11:49 ` Mark Rutland
@ 2017-04-20 1:38 ` Tan Xiaojun
2017-04-21 5:46 ` Tan Xiaojun
0 siblings, 1 reply; 18+ messages in thread
From: Tan Xiaojun @ 2017-04-20 1:38 UTC (permalink / raw)
To: linux-arm-kernel
On 2017/4/19 19:49, Mark Rutland wrote:
> Hi,
>
> Ard, this sseems to be a nomap issue. Please see below.
>
> Xiaojun, for some reason, the first message in this thread didn't seem
> to make it to LAKML (or to me). In future could you please Cc me for
> emails regarding perf on arm/arm64?
>
Sorry, this is my negligence.
> On Wed, Apr 19, 2017 at 09:44:56AM +0530, Pratyush Anand wrote:
>> On Saturday 15 April 2017 02:18 PM, Tan Xiaojun wrote:
>>> My test server is Hisilicon D03/D05 (arm64).
>>> Kernel source code is 4.11-rc6 (up to date) and config (as an attachment in the end) is generated by defconfig.
>>> (Old version does not seem to have this problem. Linux-4.1 is fine and other versions I have not tested yet.)
>>
>> I tested with mustang(ARM64) and 4.11-rc6 and could not reproduce it.
>>
>>> When I do "perf top" and annotate a random kernel symbol (like vsnprintf or others), the system report an OOPS below:
>>> (The probability of occurrence is very high, almost every time.)
>>>
>>> $ perf top
>>>
>>> Annotate vsnprintf ---- choose it
>>> Zoom into perf(7066) thread
>>> Zoom into the Kernel DSO
>>> Browse map details
>>> Run scripts for samples of thread [perf]
>>> Run scripts for samples of symbol [vsnprintf]
>>> Run scripts for all samples
>>> Exit
>
> Was perf built from the same v4.11-rc6 source tree, or was this an older
> perf binary?
>
No, I had used 4.10-rc7 or some other older perf binary.
At first, I found this problem in kernel-4.10-rc7 + perf-4.10-rc7, and then I tested the other kernel versions.
For now, I use "git bisect" and find the problem maybe between v4.5 and v4.6-rc1.
I will try more and tell you the result.
> With a perf tool built from v4.11-rc6, even with CAP_SYS_RAWIO, I see perf top
> complaining that it it cannot annotate the symbol due to a lack of a vmlinux
> file. I can't seem to convince it to use /proc/kcore.
>
> However, I can reproduce the issue by other means:
>
> # cat /proc/kcore > /dev/null
> [ 4544.984139] Unable to handle kernel paging request at virtual address ffff804392800000
> [ 4544.991995] pgd = ffff80096745f000
> [ 4544.995369] [ffff804392800000] *pgd=0000000000000000
> [ 4545.000297] Internal error: Oops: 96000005 [#1] PREEMPT SMP
> [ 4545.005815] Modules linked in:
> [ 4545.008843] CPU: 1 PID: 8976 Comm: cat Not tainted 4.11.0-rc6 #1
> [ 4545.014790] Hardware name: ARM Juno development board (r1) (DT)
> [ 4545.020653] task: ffff8009753fdb00 task.stack: ffff80097533c000
> [ 4545.026520] PC is at __memcpy+0x100/0x180
> [ 4545.030491] LR is at vread+0x144/0x280
> [ 4545.034202] pc : [<ffff0000083a1000>] lr : [<ffff0000081c126c>] pstate: 20000145
> [ 4545.041530] sp : ffff80097533fcb0
> [ 4545.044811] x29: ffff80097533fcb0 x28: ffff800962d24000
> [ 4545.050074] x27: 0000000000001000 x26: ffff8009753fdb00
> [ 4545.055337] x25: ffff000008200000 x24: ffff800977801380
> [ 4545.060600] x23: ffff8009753fdb00 x22: ffff800962d24000
> [ 4545.065863] x21: 0000000000001000 x20: ffff000008200000
> [ 4545.071125] x19: 0000000000001000 x18: 0000ffffefa323c0
> [ 4545.076387] x17: 0000ffffa9c87440 x16: ffff0000081fdfd0
> [ 4545.081649] x15: 0000ffffa9d01588 x14: 72a77346b2407be7
> [ 4545.086911] x13: 5299400690000000 x12: b0000001f9001a79
> [ 4545.092173] x11: 97fc098d91042260 x10: 0000000000000000
> [ 4545.097435] x9 : 0000000000000000 x8 : 9110626091260021
> [ 4545.102698] x7 : 0000000000001000 x6 : ffff800962d24000
> [ 4545.107960] x5 : ffff8009778013b0 x4 : 0000000000000000
> [ 4545.113222] x3 : 0400000000000001 x2 : 0000000000000f80
> [ 4545.118484] x1 : ffff804392800000 x0 : ffff800962d24000
> [ 4545.123745]
> [ 4545.125220] Process cat (pid: 8976, stack limit = 0xffff80097533c000)
> [ 4545.131598] Stack: (0xffff80097533fcb0 to 0xffff800975340000)
> [ 4545.137289] fca0: ffff80097533fd30 ffff000008270f64
> [ 4545.145049] fcc0: 000000000000e000 000000003956f000 ffff000008f950d0 ffff80097533feb8
> [ 4545.152809] fce0: 0000000000002000 ffff8009753fdb00 ffff800962d24000 ffff000008e8d3d8
> [ 4545.160568] fd00: 0000000000001000 ffff000008200000 0000000000001000 ffff800962d24000
> [ 4545.168327] fd20: 0000000000001000 ffff000008e884a0 ffff80097533fdb0 ffff00000826340c
> [ 4545.176086] fd40: ffff800976bf2800 fffffffffffffffb 000000003956d000 ffff80097533feb8
> [ 4545.183846] fd60: 0000000060000000 0000000000000015 0000000000000124 000000000000003f
> [ 4545.191605] fd80: ffff000008962000 ffff8009753fdb00 ffff8009753fdb00 ffff8009753fdb00
> [ 4545.199364] fda0: 0000000300000124 0000000000002000 ffff80097533fdd0 ffff0000081fb83c
> [ 4545.207123] fdc0: 0000000000010000 ffff80097514f900 ffff80097533fe50 ffff0000081fcb28
> [ 4545.214883] fde0: 0000000000010000 ffff80097514f900 0000000000000000 0000000000000000
> [ 4545.222642] fe00: ffff80097533fe30 ffff0000081fca1c ffff80097514f900 0000000000000000
> [ 4545.230401] fe20: 000000003956d000 ffff80097533feb8 ffff80097533fe50 ffff0000081fcb04
> [ 4545.238160] fe40: 0000000000010000 ffff80097514f900 ffff80097533fe80 ffff0000081fe014
> [ 4545.245919] fe60: ffff80097514f900 ffff80097514f900 000000003956d000 0000000000010000
> [ 4545.253678] fe80: 0000000000000000 ffff000008082f30 0000000000000000 0000800977146000
> [ 4545.261438] fea0: ffffffffffffffff 0000ffffa9c8745c 0000000000000124 0000000008202000
> [ 4545.269197] fec0: 0000000000000003 000000003956d000 0000000000010000 0000000000000000
> [ 4545.276956] fee0: 0000000000011011 0000000000000001 0000000000000011 0000000000000002
> [ 4545.284715] ff00: 000000000000003f 1f3c201f7372686b 00000000ffffffff 0000000000000030
> [ 4545.292474] ff20: 0000000000000038 0000000000000000 0000ffffa9bcca94 0000ffffa9d01588
> [ 4545.300233] ff40: 0000000000000000 0000ffffa9c87440 0000ffffefa323c0 0000000000010000
> [ 4545.307993] ff60: 000000000041a310 000000003956d000 0000000000000003 000000007fffe000
> [ 4545.315751] ff80: 00000000004088d0 0000000000010000 0000000000000000 0000000000000000
> [ 4545.323511] ffa0: 0000000000010000 0000ffffefa32690 0000000000404dcc 0000ffffefa32690
> [ 4545.331270] ffc0: 0000ffffa9c8745c 0000000060000000 0000000000000003 000000000000003f
> [ 4545.339029] ffe0: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
> [ 4545.346786] Call trace:
> [ 4545.349207] Exception stack(0xffff80097533fae0 to 0xffff80097533fc10)
> [ 4545.355586] fae0: 0000000000001000 0001000000000000 ffff80097533fcb0 ffff0000083a1000
> [ 4545.363345] fb00: 000000003957c000 ffff80097533fc00 0000000020000145 0000000000000025
> [ 4545.371105] fb20: ffff800962d24000 ffff000008e8d3d8 0000000000001000 ffff8009753fdb00
> [ 4545.378864] fb40: 0000000000000000 0000000000000002 ffff80097533fd30 ffff000008082604
> [ 4545.386623] fb60: 0000000000001000 0001000000000000 ffff80097533fd30 ffff0000083a0a90
> [ 4545.394382] fb80: ffff800962d24000 ffff804392800000 0000000000000f80 0400000000000001
> [ 4545.402140] fba0: 0000000000000000 ffff8009778013b0 ffff800962d24000 0000000000001000
> [ 4545.409899] fbc0: 9110626091260021 0000000000000000 0000000000000000 97fc098d91042260
> [ 4545.417658] fbe0: b0000001f9001a79 5299400690000000 72a77346b2407be7 0000ffffa9d01588
> [ 4545.425416] fc00: ffff0000081fdfd0 0000ffffa9c87440
> [ 4545.430248] [<ffff0000083a1000>] __memcpy+0x100/0x180
> [ 4545.435253] [<ffff000008270f64>] read_kcore+0x21c/0x3b0
> [ 4545.440429] [<ffff00000826340c>] proc_reg_read+0x64/0x90
> [ 4545.445691] [<ffff0000081fb83c>] __vfs_read+0x1c/0x108
> [ 4545.450779] [<ffff0000081fcb28>] vfs_read+0x80/0x130
> [ 4545.455696] [<ffff0000081fe014>] SyS_read+0x44/0xa0
> [ 4545.460528] [<ffff000008082f30>] el0_svc_naked+0x24/0x28
> [ 4545.465790] Code: d503201f d503201f d503201f d503201f (a8c12027)
> [ 4545.471852] ---[ end trace 4d1897f94759f461 ]---
> [ 4545.476435] note: cat[8976] exited with preempt_count 2
>
> So the call flow is:
>
> read_core() // finds the address is vmalloc or module
> -> vread()
> --> aligned_vread()
>
> In aligned_vread(), we vmalloc_to_page() the address, and find a page.
> We then try to kmap_atomic() that. The generic kmap_atomic() returns the
> linear map alias of the address.
>
> However, it appears that the page is nomap'd memory, and the linear
> alias doesn't exist. Thus memcpy explodes when trying to access that
> address.
>
> I've verified that with:
>
> ----
> diff --git a/mm/vmalloc.c b/mm/vmalloc.c
> index 0b05762..d7f48e0 100644
> --- a/mm/vmalloc.c
> +++ b/mm/vmalloc.c
> @@ -9,6 +9,7 @@
> */
>
> #include <linux/vmalloc.h>
> +#include <linux/memblock.h>
> #include <linux/mm.h>
> #include <linux/module.h>
> #include <linux/highmem.h>
> @@ -1978,6 +1979,8 @@ static int aligned_vread(char *buf, char *addr, unsigned long count)
> {
> struct page *p;
> int copied = 0;
> + phys_addr_t phys;
> + bool nomap;
>
> while (count) {
> unsigned long offset, length;
> @@ -2000,6 +2003,14 @@ static int aligned_vread(char *buf, char *addr, unsigned long count)
> * function description)
> */
> void *map = kmap_atomic(p);
> +
> + phys = page_to_phys(p);
> + nomap = !memblock_is_map_memory(phys);
> +
> + pr_info("HARK: %s kmap'd %pa (%s memory) @ %p\n",
> + __func__, &phys, (nomap ? "nomap" : "map"),
> + map);
> +
> memcpy(buf, map + offset, length);
> kunmap_atomic(map);
> } else
> ----
>
> # cat /proc/kcore > /dev/null
>
> ... which eventually results in:
>
> [ 47.360980] HARK: aligned_vread kmap'd 0x000003e290005000 (nomap memory) @ ffff83e210005000
> [ 47.369297] Unable to handle kernel paging request at virtual address ffff83e210005000
>
> I'm not sure what we should do here.
>
> I'm not immediately sure what the nomap region is. I'm using UEFI && DT,
> so I guess it's not ACPI tables.
>
> I can try to dump more info later.
>
> Thanks,
> Mark.
Thanks a lot.
Xiaojun.
>
> .
>
^ permalink raw reply [flat|nested] 18+ messages in thread
* [arm64] OOPS when using /proc/kcore to disassemble the kernel symbols in "perf top"
2017-04-20 1:38 ` Tan Xiaojun
@ 2017-04-21 5:46 ` Tan Xiaojun
2017-04-21 9:34 ` Mark Rutland
0 siblings, 1 reply; 18+ messages in thread
From: Tan Xiaojun @ 2017-04-21 5:46 UTC (permalink / raw)
To: linux-arm-kernel
On 2017/4/20 9:38, Tan Xiaojun wrote:
> On 2017/4/19 19:49, Mark Rutland wrote:
>> Hi,
>>
>> Ard, this sseems to be a nomap issue. Please see below.
>>
>> Xiaojun, for some reason, the first message in this thread didn't seem
>> to make it to LAKML (or to me). In future could you please Cc me for
>> emails regarding perf on arm/arm64?
>>
>
> Sorry, this is my negligence.
>
>> On Wed, Apr 19, 2017 at 09:44:56AM +0530, Pratyush Anand wrote:
>>> On Saturday 15 April 2017 02:18 PM, Tan Xiaojun wrote:
>>>> My test server is Hisilicon D03/D05 (arm64).
>>>> Kernel source code is 4.11-rc6 (up to date) and config (as an attachment in the end) is generated by defconfig.
>>>> (Old version does not seem to have this problem. Linux-4.1 is fine and other versions I have not tested yet.)
>>>
>>> I tested with mustang(ARM64) and 4.11-rc6 and could not reproduce it.
>>>
Hi,
Pratyush,
Sorry, could you test it again? Because I tested it many times and found it is not triggered every time.
And you can run "perf top -U" and try more kernel symbols to increase the probability of occurrence, or
maybe you can try Mark's way "cat /proc/kcore > /dev/null".
I would like to confirm whether this is hardware related, but I have no other arm64 boards except the
boards of Hisilicon.
>>>> When I do "perf top" and annotate a random kernel symbol (like vsnprintf or others), the system report an OOPS below:
>>>> (The probability of occurrence is very high, almost every time.)
>>>>
>>>> $ perf top
>>>>
>>>> Annotate vsnprintf ---- choose it
>>>> Zoom into perf(7066) thread
>>>> Zoom into the Kernel DSO
>>>> Browse map details
>>>> Run scripts for samples of thread [perf]
>>>> Run scripts for samples of symbol [vsnprintf]
>>>> Run scripts for all samples
>>>> Exit
>>
>> Was perf built from the same v4.11-rc6 source tree, or was this an older
>> perf binary?
>>
>
> No, I had used 4.10-rc7 or some other older perf binary.
> At first, I found this problem in kernel-4.10-rc7 + perf-4.10-rc7, and then I tested the other kernel versions.
>
> For now, I use "git bisect" and find the problem maybe between v4.5 and v4.6-rc1.
>
> I will try more and tell you the result.
>
Hi,
Mark, Ard,
I found the patch which introduced the problem.
The commit is:
commit f9040773b7bbbd9e98eb6184a263512a7cfc133f
Author: Ard Biesheuvel <ard.biesheuvel@linaro.org>
Date: Tue Feb 16 13:52:40 2016 +0100
arm64: move kernel image to base of vmalloc area
This moves the module area to right before the vmalloc area, and moves
the kernel image to the base of the vmalloc area. This is an intermediate
step towards implementing KASLR, which allows the kernel image to be
located anywhere in the vmalloc area.
Since other subsystems such as hibernate may still need to refer to the
kernel text or data segments via their linears addresses, both are mapped
in the linear region as well. The linear alias of the text region is
mapped read-only/non-executable to prevent inadvertent modification or
execution.
Signed-off-by: Ard Biesheuvel <ard.biesheuvel@linaro.org>
Signed-off-by: Catalin Marinas <catalin.marinas@arm.com>
It can work well without this patch in Linux-4.5-rc4. And it can trigger an OOPS with this patch in Linux-4.5-rc4.
I try to revert it in v4.11-rc6, but it involves too much conflict.
So I need to understand this patch fist. Then I can known where the problem is.
Thanks.
Xiaojun.
>> With a perf tool built from v4.11-rc6, even with CAP_SYS_RAWIO, I see perf top
>> complaining that it it cannot annotate the symbol due to a lack of a vmlinux
>> file. I can't seem to convince it to use /proc/kcore.
>>
>> However, I can reproduce the issue by other means:
>>
>> # cat /proc/kcore > /dev/null
>> [ 4544.984139] Unable to handle kernel paging request at virtual address ffff804392800000
>> [ 4544.991995] pgd = ffff80096745f000
>> [ 4544.995369] [ffff804392800000] *pgd=0000000000000000
>> [ 4545.000297] Internal error: Oops: 96000005 [#1] PREEMPT SMP
>> [ 4545.005815] Modules linked in:
>> [ 4545.008843] CPU: 1 PID: 8976 Comm: cat Not tainted 4.11.0-rc6 #1
>> [ 4545.014790] Hardware name: ARM Juno development board (r1) (DT)
>> [ 4545.020653] task: ffff8009753fdb00 task.stack: ffff80097533c000
>> [ 4545.026520] PC is at __memcpy+0x100/0x180
>> [ 4545.030491] LR is at vread+0x144/0x280
>> [ 4545.034202] pc : [<ffff0000083a1000>] lr : [<ffff0000081c126c>] pstate: 20000145
>> [ 4545.041530] sp : ffff80097533fcb0
>> [ 4545.044811] x29: ffff80097533fcb0 x28: ffff800962d24000
>> [ 4545.050074] x27: 0000000000001000 x26: ffff8009753fdb00
>> [ 4545.055337] x25: ffff000008200000 x24: ffff800977801380
>> [ 4545.060600] x23: ffff8009753fdb00 x22: ffff800962d24000
>> [ 4545.065863] x21: 0000000000001000 x20: ffff000008200000
>> [ 4545.071125] x19: 0000000000001000 x18: 0000ffffefa323c0
>> [ 4545.076387] x17: 0000ffffa9c87440 x16: ffff0000081fdfd0
>> [ 4545.081649] x15: 0000ffffa9d01588 x14: 72a77346b2407be7
>> [ 4545.086911] x13: 5299400690000000 x12: b0000001f9001a79
>> [ 4545.092173] x11: 97fc098d91042260 x10: 0000000000000000
>> [ 4545.097435] x9 : 0000000000000000 x8 : 9110626091260021
>> [ 4545.102698] x7 : 0000000000001000 x6 : ffff800962d24000
>> [ 4545.107960] x5 : ffff8009778013b0 x4 : 0000000000000000
>> [ 4545.113222] x3 : 0400000000000001 x2 : 0000000000000f80
>> [ 4545.118484] x1 : ffff804392800000 x0 : ffff800962d24000
>> [ 4545.123745]
>> [ 4545.125220] Process cat (pid: 8976, stack limit = 0xffff80097533c000)
>> [ 4545.131598] Stack: (0xffff80097533fcb0 to 0xffff800975340000)
>> [ 4545.137289] fca0: ffff80097533fd30 ffff000008270f64
>> [ 4545.145049] fcc0: 000000000000e000 000000003956f000 ffff000008f950d0 ffff80097533feb8
>> [ 4545.152809] fce0: 0000000000002000 ffff8009753fdb00 ffff800962d24000 ffff000008e8d3d8
>> [ 4545.160568] fd00: 0000000000001000 ffff000008200000 0000000000001000 ffff800962d24000
>> [ 4545.168327] fd20: 0000000000001000 ffff000008e884a0 ffff80097533fdb0 ffff00000826340c
>> [ 4545.176086] fd40: ffff800976bf2800 fffffffffffffffb 000000003956d000 ffff80097533feb8
>> [ 4545.183846] fd60: 0000000060000000 0000000000000015 0000000000000124 000000000000003f
>> [ 4545.191605] fd80: ffff000008962000 ffff8009753fdb00 ffff8009753fdb00 ffff8009753fdb00
>> [ 4545.199364] fda0: 0000000300000124 0000000000002000 ffff80097533fdd0 ffff0000081fb83c
>> [ 4545.207123] fdc0: 0000000000010000 ffff80097514f900 ffff80097533fe50 ffff0000081fcb28
>> [ 4545.214883] fde0: 0000000000010000 ffff80097514f900 0000000000000000 0000000000000000
>> [ 4545.222642] fe00: ffff80097533fe30 ffff0000081fca1c ffff80097514f900 0000000000000000
>> [ 4545.230401] fe20: 000000003956d000 ffff80097533feb8 ffff80097533fe50 ffff0000081fcb04
>> [ 4545.238160] fe40: 0000000000010000 ffff80097514f900 ffff80097533fe80 ffff0000081fe014
>> [ 4545.245919] fe60: ffff80097514f900 ffff80097514f900 000000003956d000 0000000000010000
>> [ 4545.253678] fe80: 0000000000000000 ffff000008082f30 0000000000000000 0000800977146000
>> [ 4545.261438] fea0: ffffffffffffffff 0000ffffa9c8745c 0000000000000124 0000000008202000
>> [ 4545.269197] fec0: 0000000000000003 000000003956d000 0000000000010000 0000000000000000
>> [ 4545.276956] fee0: 0000000000011011 0000000000000001 0000000000000011 0000000000000002
>> [ 4545.284715] ff00: 000000000000003f 1f3c201f7372686b 00000000ffffffff 0000000000000030
>> [ 4545.292474] ff20: 0000000000000038 0000000000000000 0000ffffa9bcca94 0000ffffa9d01588
>> [ 4545.300233] ff40: 0000000000000000 0000ffffa9c87440 0000ffffefa323c0 0000000000010000
>> [ 4545.307993] ff60: 000000000041a310 000000003956d000 0000000000000003 000000007fffe000
>> [ 4545.315751] ff80: 00000000004088d0 0000000000010000 0000000000000000 0000000000000000
>> [ 4545.323511] ffa0: 0000000000010000 0000ffffefa32690 0000000000404dcc 0000ffffefa32690
>> [ 4545.331270] ffc0: 0000ffffa9c8745c 0000000060000000 0000000000000003 000000000000003f
>> [ 4545.339029] ffe0: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
>> [ 4545.346786] Call trace:
>> [ 4545.349207] Exception stack(0xffff80097533fae0 to 0xffff80097533fc10)
>> [ 4545.355586] fae0: 0000000000001000 0001000000000000 ffff80097533fcb0 ffff0000083a1000
>> [ 4545.363345] fb00: 000000003957c000 ffff80097533fc00 0000000020000145 0000000000000025
>> [ 4545.371105] fb20: ffff800962d24000 ffff000008e8d3d8 0000000000001000 ffff8009753fdb00
>> [ 4545.378864] fb40: 0000000000000000 0000000000000002 ffff80097533fd30 ffff000008082604
>> [ 4545.386623] fb60: 0000000000001000 0001000000000000 ffff80097533fd30 ffff0000083a0a90
>> [ 4545.394382] fb80: ffff800962d24000 ffff804392800000 0000000000000f80 0400000000000001
>> [ 4545.402140] fba0: 0000000000000000 ffff8009778013b0 ffff800962d24000 0000000000001000
>> [ 4545.409899] fbc0: 9110626091260021 0000000000000000 0000000000000000 97fc098d91042260
>> [ 4545.417658] fbe0: b0000001f9001a79 5299400690000000 72a77346b2407be7 0000ffffa9d01588
>> [ 4545.425416] fc00: ffff0000081fdfd0 0000ffffa9c87440
>> [ 4545.430248] [<ffff0000083a1000>] __memcpy+0x100/0x180
>> [ 4545.435253] [<ffff000008270f64>] read_kcore+0x21c/0x3b0
>> [ 4545.440429] [<ffff00000826340c>] proc_reg_read+0x64/0x90
>> [ 4545.445691] [<ffff0000081fb83c>] __vfs_read+0x1c/0x108
>> [ 4545.450779] [<ffff0000081fcb28>] vfs_read+0x80/0x130
>> [ 4545.455696] [<ffff0000081fe014>] SyS_read+0x44/0xa0
>> [ 4545.460528] [<ffff000008082f30>] el0_svc_naked+0x24/0x28
>> [ 4545.465790] Code: d503201f d503201f d503201f d503201f (a8c12027)
>> [ 4545.471852] ---[ end trace 4d1897f94759f461 ]---
>> [ 4545.476435] note: cat[8976] exited with preempt_count 2
>>
>> So the call flow is:
>>
>> read_core() // finds the address is vmalloc or module
>> -> vread()
>> --> aligned_vread()
>>
>> In aligned_vread(), we vmalloc_to_page() the address, and find a page.
>> We then try to kmap_atomic() that. The generic kmap_atomic() returns the
>> linear map alias of the address.
>>
>> However, it appears that the page is nomap'd memory, and the linear
>> alias doesn't exist. Thus memcpy explodes when trying to access that
>> address.
>>
>> I've verified that with:
>>
>> ----
>> diff --git a/mm/vmalloc.c b/mm/vmalloc.c
>> index 0b05762..d7f48e0 100644
>> --- a/mm/vmalloc.c
>> +++ b/mm/vmalloc.c
>> @@ -9,6 +9,7 @@
>> */
>>
>> #include <linux/vmalloc.h>
>> +#include <linux/memblock.h>
>> #include <linux/mm.h>
>> #include <linux/module.h>
>> #include <linux/highmem.h>
>> @@ -1978,6 +1979,8 @@ static int aligned_vread(char *buf, char *addr, unsigned long count)
>> {
>> struct page *p;
>> int copied = 0;
>> + phys_addr_t phys;
>> + bool nomap;
>>
>> while (count) {
>> unsigned long offset, length;
>> @@ -2000,6 +2003,14 @@ static int aligned_vread(char *buf, char *addr, unsigned long count)
>> * function description)
>> */
>> void *map = kmap_atomic(p);
>> +
>> + phys = page_to_phys(p);
>> + nomap = !memblock_is_map_memory(phys);
>> +
>> + pr_info("HARK: %s kmap'd %pa (%s memory) @ %p\n",
>> + __func__, &phys, (nomap ? "nomap" : "map"),
>> + map);
>> +
>> memcpy(buf, map + offset, length);
>> kunmap_atomic(map);
>> } else
>> ----
>>
>> # cat /proc/kcore > /dev/null
>>
>> ... which eventually results in:
>>
>> [ 47.360980] HARK: aligned_vread kmap'd 0x000003e290005000 (nomap memory) @ ffff83e210005000
>> [ 47.369297] Unable to handle kernel paging request at virtual address ffff83e210005000
>>
>> I'm not sure what we should do here.
>>
>> I'm not immediately sure what the nomap region is. I'm using UEFI && DT,
>> so I guess it's not ACPI tables.
>>
>> I can try to dump more info later.
>>
>> Thanks,
>> Mark.
>
> Thanks a lot.
> Xiaojun.
>
>>
>> .
>>
>
^ permalink raw reply [flat|nested] 18+ messages in thread
* [arm64] OOPS when using /proc/kcore to disassemble the kernel symbols in "perf top"
2017-04-21 5:46 ` Tan Xiaojun
@ 2017-04-21 9:34 ` Mark Rutland
2017-04-24 1:02 ` Tan Xiaojun
0 siblings, 1 reply; 18+ messages in thread
From: Mark Rutland @ 2017-04-21 9:34 UTC (permalink / raw)
To: linux-arm-kernel
Hi,
On Fri, Apr 21, 2017 at 01:46:43PM +0800, Tan Xiaojun wrote:
> On 2017/4/20 9:38, Tan Xiaojun wrote:
> > On 2017/4/19 19:49, Mark Rutland wrote:
> >> Hi,
> >>
> >> Ard, this sseems to be a nomap issue. Please see below.
> >>
> >> Xiaojun, for some reason, the first message in this thread didn't seem
> >> to make it to LAKML (or to me). In future could you please Cc me for
> >> emails regarding perf on arm/arm64?
> >>
> >
> > Sorry, this is my negligence.
> >
> >> On Wed, Apr 19, 2017 at 09:44:56AM +0530, Pratyush Anand wrote:
> >>> On Saturday 15 April 2017 02:18 PM, Tan Xiaojun wrote:
> >>>> My test server is Hisilicon D03/D05 (arm64).
> >>>> Kernel source code is 4.11-rc6 (up to date) and config (as an attachment in the end) is generated by defconfig.
> >>>> (Old version does not seem to have this problem. Linux-4.1 is fine and other versions I have not tested yet.)
> >>>
> >>> I tested with mustang(ARM64) and 4.11-rc6 and could not reproduce it.
> >>>
>
> Hi,
> Pratyush,
>
> Sorry, could you test it again? Because I tested it many times and found it is not triggered every time.
> And you can run "perf top -U" and try more kernel symbols to increase the probability of occurrence, or
> maybe you can try Mark's way "cat /proc/kcore > /dev/null".
>
> I would like to confirm whether this is hardware related, but I have no other arm64 boards except the
> boards of Hisilicon.
As I mentioned in my prior reply, this is a bug in the way we handle
nomap memory in the kernel.
This is not hardware related, and this is not specific to perf.
The kcore code expects that if a vmalloc mapping has a corresponding
struct page, that it can be accessed via the linear mapping. However,
this is not true for nomap memory.
> I found the patch which introduced the problem.
> The commit is:
>
> commit f9040773b7bbbd9e98eb6184a263512a7cfc133f
> Author: Ard Biesheuvel <ard.biesheuvel@linaro.org>
> Date: Tue Feb 16 13:52:40 2016 +0100
>
> arm64: move kernel image to base of vmalloc area
>
> This moves the module area to right before the vmalloc area, and moves
> the kernel image to the base of the vmalloc area. This is an intermediate
> step towards implementing KASLR, which allows the kernel image to be
> located anywhere in the vmalloc area.
>
> Since other subsystems such as hibernate may still need to refer to the
> kernel text or data segments via their linears addresses, both are mapped
> in the linear region as well. The linear alias of the text region is
> mapped read-only/non-executable to prevent inadvertent modification or
> execution.
>
> Signed-off-by: Ard Biesheuvel <ard.biesheuvel@linaro.org>
> Signed-off-by: Catalin Marinas <catalin.marinas@arm.com>
>
> It can work well without this patch in Linux-4.5-rc4. And it can
> trigger an OOPS with this patch in Linux-4.5-rc4.
>
> I try to revert it in v4.11-rc6, but it involves too much conflict.
> So I need to understand this patch fist. Then I can known where the problem is.
Reverting this patch is not the correct fix.
The fix will either be changing the way we set things up for nomap
memory, or with additions to the kcore or vread code to cater for nomap.
Thanks,
Mark.
^ permalink raw reply [flat|nested] 18+ messages in thread
* [arm64] OOPS when using /proc/kcore to disassemble the kernel symbols in "perf top"
2017-04-21 9:34 ` Mark Rutland
@ 2017-04-24 1:02 ` Tan Xiaojun
0 siblings, 0 replies; 18+ messages in thread
From: Tan Xiaojun @ 2017-04-24 1:02 UTC (permalink / raw)
To: linux-arm-kernel
On 2017/4/21 17:34, Mark Rutland wrote:
> Hi,
>
> On Fri, Apr 21, 2017 at 01:46:43PM +0800, Tan Xiaojun wrote:
>> On 2017/4/20 9:38, Tan Xiaojun wrote:
>>> On 2017/4/19 19:49, Mark Rutland wrote:
>>>> Hi,
>>>>
>>>> Ard, this sseems to be a nomap issue. Please see below.
>>>>
>>>> Xiaojun, for some reason, the first message in this thread didn't seem
>>>> to make it to LAKML (or to me). In future could you please Cc me for
>>>> emails regarding perf on arm/arm64?
>>>>
>>>
>>> Sorry, this is my negligence.
>>>
>>>> On Wed, Apr 19, 2017 at 09:44:56AM +0530, Pratyush Anand wrote:
>>>>> On Saturday 15 April 2017 02:18 PM, Tan Xiaojun wrote:
>>>>>> My test server is Hisilicon D03/D05 (arm64).
>>>>>> Kernel source code is 4.11-rc6 (up to date) and config (as an attachment in the end) is generated by defconfig.
>>>>>> (Old version does not seem to have this problem. Linux-4.1 is fine and other versions I have not tested yet.)
>>>>>
>>>>> I tested with mustang(ARM64) and 4.11-rc6 and could not reproduce it.
>>>>>
>>
>> Hi,
>> Pratyush,
>>
>> Sorry, could you test it again? Because I tested it many times and found it is not triggered every time.
>> And you can run "perf top -U" and try more kernel symbols to increase the probability of occurrence, or
>> maybe you can try Mark's way "cat /proc/kcore > /dev/null".
>>
>> I would like to confirm whether this is hardware related, but I have no other arm64 boards except the
>> boards of Hisilicon.
>
> As I mentioned in my prior reply, this is a bug in the way we handle
> nomap memory in the kernel.
>
> This is not hardware related, and this is not specific to perf.
>
> The kcore code expects that if a vmalloc mapping has a corresponding
> struct page, that it can be accessed via the linear mapping. However,
> this is not true for nomap memory.
>
Yes, you are right.
>> I found the patch which introduced the problem.
>> The commit is:
>>
>> commit f9040773b7bbbd9e98eb6184a263512a7cfc133f
>> Author: Ard Biesheuvel <ard.biesheuvel@linaro.org>
>> Date: Tue Feb 16 13:52:40 2016 +0100
>>
>> arm64: move kernel image to base of vmalloc area
>>
>> This moves the module area to right before the vmalloc area, and moves
>> the kernel image to the base of the vmalloc area. This is an intermediate
>> step towards implementing KASLR, which allows the kernel image to be
>> located anywhere in the vmalloc area.
>>
>> Since other subsystems such as hibernate may still need to refer to the
>> kernel text or data segments via their linears addresses, both are mapped
>> in the linear region as well. The linear alias of the text region is
>> mapped read-only/non-executable to prevent inadvertent modification or
>> execution.
>>
>> Signed-off-by: Ard Biesheuvel <ard.biesheuvel@linaro.org>
>> Signed-off-by: Catalin Marinas <catalin.marinas@arm.com>
>>
>> It can work well without this patch in Linux-4.5-rc4. And it can
>> trigger an OOPS with this patch in Linux-4.5-rc4.
>>
>> I try to revert it in v4.11-rc6, but it involves too much conflict.
>> So I need to understand this patch fist. Then I can known where the problem is.
>
> Reverting this patch is not the correct fix.
>
> The fix will either be changing the way we set things up for nomap
> memory, or with additions to the kcore or vread code to cater for nomap.
>
It seems that the problem is serious and I want to fix it as soon as possible. But I know little
about nomap memory. So if you can give a fix patch, I am glad to test it. ^-^
Thanks.
Xiaojun.
> Thanks,
> Mark.
> .
>
^ permalink raw reply [flat|nested] 18+ messages in thread
end of thread, other threads:[~2017-04-24 1:02 UTC | newest]
Thread overview: 18+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2017-02-23 6:04 [PATCH] perf/core: Fix to check perf_cpu_time_max_percent Tan Xiaojun
2017-02-24 9:15 ` [tip:perf/urgent] perf/core: Fix the perf_cpu_time_max_percent check tip-bot for Tan Xiaojun
2017-02-25 8:10 ` Tan Xiaojun
2017-02-25 8:10 ` Tan Xiaojun
2017-02-25 9:51 ` Peter Zijlstra
2017-02-25 9:51 ` Peter Zijlstra
2017-02-27 0:36 ` Tan Xiaojun
2017-02-27 0:36 ` Tan Xiaojun
2017-03-13 18:35 ` Vince Weaver
2017-03-14 1:52 ` Tan Xiaojun
2017-04-15 7:58 ` [BUG arm64] OOPS when using /proc/kcore to disassemble the kernel symbols in "perf top" Tan Xiaojun
[not found] ` <58F1DE6A.7050307@huawei.com>
2017-04-19 4:14 ` [arm64] " Pratyush Anand
2017-04-19 8:01 ` Tan Xiaojun
2017-04-19 11:49 ` Mark Rutland
2017-04-20 1:38 ` Tan Xiaojun
2017-04-21 5:46 ` Tan Xiaojun
2017-04-21 9:34 ` Mark Rutland
2017-04-24 1:02 ` Tan Xiaojun
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.