[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <20170524181648.GA8951@wotan.suse.de>
Date: Wed, 24 May 2017 20:16:48 +0200
From: "Luis R. Rodriguez" <mcgrof@...nel.org>
To: Steven Rostedt <rostedt@...dmis.org>
Cc: Thomas Gleixner <tglx@...utronix.de>,
Kees Cook <keescook@...omium.org>,
LKML <linux-kernel@...r.kernel.org>, x86@...nel.org,
Masami Hiramatsu <mhiramat@...nel.org>,
"Luis R. Rodriguez" <mcgrof@...nel.org>,
Peter Zijlstra <peterz@...radead.org>
Subject: Re: [PATCH] x86/ftrace: Make sure that ftrace trampolines are not RWX
On Wed, May 24, 2017 at 01:47:28PM -0400, Steven Rostedt wrote:
> OK, it crashed on one of my tests. I removed the patch and it boots
> fine, and crashes when I add it back.
>
> Here's the crash:
>
> Running tests on all trace events:
> Testing all events: OK
> Testing ftrace filter: OK
> trace_kprobe: Testing kprobe tracing:
> BUG: unable to handle kernel paging request at ffff880214f5c000
> IP: new_slab+0x1e8/0x2b4
> PGD 338c067
> P4D 338c067
> PUD 338f067
> PMD 212022063
> PTE 8000000214f5c161
The good news is that this also fixes the other issue I reported with
CONFIG_KPROBES_SANITY_TEST=y and the same WARN complaint without a crash [0].
Please note that the issue I reported actually is present since the
infrastructure to report on these warnings was added through commit
e1a58320a38dfa72be48a0f1a3a92273663ba6db ("x86/mm: Warn on W^X mappings")
which was added through kernel 4.3.0-rc3.
Thomas's patch says: "Fixes: f3bea49115b2 ("ftrace/x86: Add dynamic allocated
trampoline for ftrace_ops"), and this was added through kernel v3.19-rc1 so it
may well be the same issue given the traces on my issue also reflect a
module_alloc() trace after arch_ftrace_update_trampoline() which matches what
Thomas also saw when inspecting his buggy page with kmemleak echo dump [1].
[0] https://lkml.kernel.org/r/20170524175508.GZ8951@wotan.suse.de
[1] https://lkml.kernel.org/r/alpine.DEB.2.20.1705232243520.2409@nanos
BUT I'm also able to reprorduce a crash too though easily, as follows where
as before this commit it was passing all 45 tests just fine:
mcgrof@...gy ~/linux-next (git::next-20170519)$ sudo tools/testing/selftests/ftrace/ftracetest
=== Ftrace unit tests ===
[1] Basic trace file check [PASS]
[2] Basic test for tracers [PASS]
[3] Basic trace clock test [PASS]
[4] Basic event tracing check [PASS]
[5] event tracing - enable/disable with event level files [PASS]
[6] event tracing - restricts events based on pid [PASS]
[7] event tracing - enable/disable with subsystem level files [PASS]
[8] event tracing - enable/disable with top level files [PASS]
[9] ftrace - function graph filters with stack tracer [PASS]
[10] ftrace - function graph filters [PASS]
[11] ftrace - test for function event triggers
<it hangs there>
I managed to get the kernel log:
[ 429.416279] in mmio_trace_init
[ 429.504315] mmiotrace: Disabling non-boot CPUs...
[ 429.545572] Unregister pv shared memory for cpu 1
[ 429.551725] smpboot: CPU 1 is now offline
[ 429.553044] mmiotrace: CPU1 is down.
[ 429.572874] Unregister pv shared memory for cpu 2
[ 429.576361] smpboot: CPU 2 is now offline
[ 429.578355] mmiotrace: CPU2 is down.
[ 429.596755] Unregister pv shared memory for cpu 3
[ 429.601946] smpboot: CPU 3 is now offline
[ 429.602768] mmiotrace: CPU3 is down.
[ 429.603418] mmiotrace: enabled.
[ 429.605001] in mmio_trace_reset
[ 429.605003] mmiotrace: Re-enabling CPUs...
[ 429.605933] x86: Booting SMP configuration:
[ 429.606505] smpboot: Booting Node 0 Processor 1 APIC 0x1
[ 429.617989] kvm-clock: cpu 1, msr 1:3fff0041, secondary cpu clock
[ 429.640600] KVM setup async PF for cpu 1
[ 429.640603] kvm-stealtime: cpu 1, msr 13fc8da40
[ 429.642384] mmiotrace: enabled CPU1.
[ 429.643391] smpboot: Booting Node 0 Processor 2 APIC 0x2
[ 429.654788] kvm-clock: cpu 2, msr 1:3fff0081, secondary cpu clock
[ 429.675512] KVM setup async PF for cpu 2
[ 429.675921] kvm-stealtime: cpu 2, msr 13fd0da40
[ 429.676895] mmiotrace: enabled CPU2.
[ 429.678531] smpboot: Booting Node 0 Processor 3 APIC 0x3
[ 429.689999] kvm-clock: cpu 3, msr 1:3fff00c1, secondary cpu clock
[ 429.710808] KVM setup async PF for cpu 3
[ 429.711183] kvm-stealtime: cpu 3, msr 13fd8da40
[ 429.712123] mmiotrace: enabled CPU3.
[ 429.728330] mmiotrace: disabled.
[ 440.537183] BUG: unable to handle kernel paging request at ffff964cf9376000
[ 440.538899] IP: tlb_next_batch.isra.54+0x41/0x70
[ 440.540022] PGD b736f067
[ 440.540024] P4D b736f067
[ 440.540707] PUD b7373067
[ 440.541318] PMD 12ff82063
[ 440.541953] PTE 8000000139376161
[ 440.543555] Oops: 0003 [#1] SMP
[ 440.543966] Modules linked in: ppdev(E) joydev(E) evdev(E) serio_raw(E) pcspkr(E) bochs_drm(E) drm_kms_helper(E) ttm(E) drm(E) i2c_piix4(E) sg(E) parport_pc(E) parport(E) acpi_cpufreq(E) button(E) sch_fq_codel(E) autofs4(E) crc32c_generic(E) ext4(E) crc16(E) jbd2(E) mbcache(E) sr_mod(E) cdrom(E) sd_mod(E) ata_generic(E) psmouse(E) floppy(E) ata_piix(E) e1000(E) libata(E) scsi_mod(E)
[ 440.548057] CPU: 2 PID: 1765 Comm: ftracetest Tainted: G E 4.12.0-rc1-next-20170519+ #155
[ 440.549159] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.10.2-0-g5f4c7b1-prebuilt.qemu-project.org 04/01/2014
[ 440.550329] task: ffff964cf14e2600 task.stack: ffffbe7c80b58000
[ 440.550921] RIP: 0010:tlb_next_batch.isra.54+0x41/0x70
[ 440.551385] RSP: 0018:ffffbe7c80b5bc40 EFLAGS: 00010202
[ 440.551855] RAX: ffff964cf9376000 RBX: ffffbe7c80b5bdf0 RCX: 000000000001dd18
[ 440.552493] RDX: 0000000000000000 RSI: 0000000000000011 RDI: 0000000000000246
[ 440.553134] RBP: ffffbe7c80b5bc50 R08: ffff964cf0b6d958 R09: 0000000000000000
[ 440.553750] R10: 0000000000000000 R11: 0000000000000000 R12: ffffbe7c80b5be48
[ 440.554386] R13: ffffbe7c80b5bdd0 R14: 00005560d7a30000 R15: ffff964cf035c178
[ 440.555025] FS: 0000000000000000(0000) GS:ffff964cffd00000(0000) knlGS:0000000000000000
[ 440.555743] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 440.556255] CR2: ffff964cf9376000 CR3: 0000000139688000 CR4: 00000000000006e0
[ 440.556895] Call Trace:
[ 440.557107] unmap_page_range+0x722/0x930
[ 440.557443] ? cpumask_any_but+0x24/0x40
[ 440.557773] unmap_single_vma+0x59/0xe0
[ 440.558088] ? lru_deactivate_file_fn+0x360/0x360
[ 440.558485] unmap_vmas+0x51/0xa0
[ 440.558769] exit_mmap+0xa7/0x170
[ 440.559054] mmput+0x53/0x140
[ 440.559309] do_exit+0x286/0xb30
[ 440.559582] ? __do_page_fault+0x266/0x4e0
[ 440.559928] do_group_exit+0x43/0xb0
[ 440.560230] SyS_exit_group+0x14/0x20
[ 440.560539] entry_SYSCALL_64_fastpath+0x1e/0xa9
[ 440.560963] RIP: 0033:0x7f9533db24d8
[ 440.561287] RSP: 002b:00007ffda4899cf8 EFLAGS: 00000246 ORIG_RAX: 00000000000000e7
[ 440.561963] RAX: ffffffffffffffda RBX: 00005560d821c110 RCX: 00007f9533db24d8
[ 440.562601] RDX: 0000000000000000 RSI: 000000000000003c RDI: 0000000000000000
[ 440.563253] RBP: 00007f9534092b00 R08: 00000000000000e7 R09: ffffffffffffff98
[ 440.563863] R10: 00005560d82208a0 R11: 0000000000000246 R12: 0000000000000000
[ 440.564437] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
[ 440.565023] Code: 00 00 c3 83 3e 13 74 4f 55 48 89 e5 41 54 53 49 89 f4 48 89 fb 31 f6 bf 00 02 00 01 e8 d9 f0 fc ff 48 85 c0 74 2d 41 83 04 24 01 <48> c7 00 00 00 00 00 c7 40 08 00 00 00 00 c7 40 0c fe 01 00 00
[ 440.566681] RIP: tlb_next_batch.isra.54+0x41/0x70 RSP: ffffbe7c80b5bc40
[ 440.567283] CR2: ffff964cf9376000
[ 440.567592] ---[ end trace 382f2593927e722f ]---
[ 440.567991] Fixing recursive fault but reboot is needed!
Luis
Powered by blists - more mailing lists