Messages in this thread | | | Date | Wed, 24 May 2017 20:16:48 +0200 | From | "Luis R. Rodriguez" <> | 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@piggy ~/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
| |