Re: [PATCH v3 1/3] tracing: Show real address for trace event arguments

[Jon Hunter <jonathanh@nvidia.com>]

On 15/10/2020 15:55, Masami Hiramatsu wrote:
> To help debugging kernel, show real address for trace event arguments
> in tracefs/trace{,pipe} instead of hashed pointer value.
> 
> Since ftrace human-readable format uses vsprintf(), all %p are
> translated to hash values instead of pointer address.
> 
> However, when debugging the kernel, raw address value gives a
> hint when comparing with the memory mapping in the kernel.
> (Those are sometimes used with crash log, which is not hashed too)
> So converting %p with %px when calling trace_seq_printf().
> 
> Moreover, this is not improving the security because the tracefs
> can be used only by root user and the raw address values are readable
> from tracefs/percpu/cpu*/trace_pipe_raw file.
> 
> Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org>


I have encountered the following crash on a couple of our ARM64 Jetson
platforms and bisect is pointing to this change. The crash I am seeing
is on boot when I am directing the trace prints to the console by adding
'tp_printk trace_event="cpu_frequency,cpu_frequency_limits"' to the
kernel command line and enabling CONFIG_BOOTTIME_TRACING. Reverting this
change does fix the problem. Let me know if you have any thoughts.

[    5.731301] Unable to handle kernel paging request at virtual address
fbf80000800040f8
[    5.739215] Mem abort info:
[    5.742004]   ESR = 0x96000004
[    5.745054]   EC = 0x25: DABT (current EL), IL = 32 bits
[    5.750359]   SET = 0, FnV = 0
[    5.753408]   EA = 0, S1PTW = 0
[    5.756543] Data abort info:
[    5.759416]   ISV = 0, ISS = 0x00000004
[    5.763244]   CM = 0, WnR = 0
[    5.766205] [fbf80000800040f8] address between user and kernel
address ranges
[    5.773332] Internal error: Oops: 96000004 [#1] PREEMPT SMP
[    5.778898] Modules linked in:
[    5.781952] CPU: 5 PID: 44 Comm: kworker/5:1 Tainted: G S
    5.12.0-rc8 #1
[    5.789861] Hardware name: NVIDIA Jetson TX2 Developer Kit (DT)
[    5.795773] Workqueue: events deferred_probe_work_func
[    5.800913] pstate: 60000085 (nZCv daIf -PAN -UAO -TCO BTYPE=--)
[    5.806911] pc : trace_event_format+0x28/0x1a0
[    5.811353] lr : trace_event_printf+0x50/0x98
[    5.815706] sp : ffff80001230b760
[    5.819014] x29: ffff80001230b760 x28: ffff800011e99c10
[    5.824324] x27: ffff000082d9ce18 x26: ffff8000115abd30
[    5.829630] x25: 0000000000000000 x24: ffff800011f3e040
[    5.834937] x23: ffff0000800050c8 x22: ffff000080004000
[    5.840242] x21: ffff800012276e38 x20: ffff000080004000
[    5.845549] x19: ffff800011e99948 x18: ffffffffffffffff
[    5.850854] x17: 0000000000000007 x16: 0000000000000001
[    5.856161] x15: ffff800011e99948 x14: ffff000082d15688
[    5.861468] x13: ffff000082d15687 x12: 0000000000000018
[    5.866774] x11: 0101010101010101 x10: 7f7f7f7f7f7f7f7f
[    5.872082] x9 : 0000000000000090 x8 : 0000000000000095
[    5.877389] x7 : 0000000000000014 x6 : ffff0000800050de
[    5.882695] x5 : 0000000000000000 x4 : 0000000000000000
[    5.888002] x3 : ffff80001230b820 x2 : 00000000ffffffd0
[    5.893308] x1 : ffff8000115abd30 x0 : fbf8000080004080
[    5.898615] Call trace:
[    5.901056]  trace_event_format+0x28/0x1a0
[    5.905147]  trace_event_printf+0x50/0x98
[    5.909151]  trace_raw_output_cpu_frequency_limits+0x48/0x60
[    5.914807]  trace_event_buffer_commit+0x1bc/0x288
[    5.919592]  trace_event_raw_event_cpu_frequency_limits+0x78/0xd0
[    5.925679]  __traceiter_cpu_frequency_limits+0x30/0x48
[    5.930899]  cpufreq_set_policy+0x15c/0x288
[    5.935079]  cpufreq_online+0x6f4/0x928
[    5.938910]  cpufreq_add_dev+0x78/0x88
[    5.942654]  subsys_interface_register+0x9c/0xf0
[    5.947266]  cpufreq_register_driver+0x170/0x218
[    5.951878]  tegra186_cpufreq_probe+0x164/0x350
[    5.956404]  platform_probe+0x90/0xd8
[    5.960061]  really_probe+0x20c/0x3e8
[    5.963720]  driver_probe_device+0x54/0xb8
[    5.967812]  __device_attach_driver+0x90/0xc0
[    5.972161]  bus_for_each_drv+0x70/0xc8
[    5.975992]  __device_attach+0xec/0x150
[    5.979825]  device_initial_probe+0x10/0x18
[    5.984002]  bus_probe_device+0x94/0xa0
[    5.987833]  deferred_probe_work_func+0x80/0xb8
[    5.992359]  process_one_work+0x1f0/0x4b8
[    5.996368]  worker_thread+0x20c/0x450
[    6.000112]  kthread+0x124/0x150
[    6.003337]  ret_from_fork+0x10/0x18
[    6.006913] Code: b4000b21 aa0003f6 f9400000 aa0103fa (b9407800)
[    6.013000] ---[ end trace eae1531f47c7c14a ]---

Thanks!
Jon

-- 
nvpublic