On 04/06/2015 07:24 AM, Borislav Petkov wrote: > On Sun, Apr 05, 2015 at 11:59:52PM -0400, Sasha Levin wrote: >> Hi all, >> >> I'm seeing an interesting hang when trinity is trying to load a large module, where >> the size passed by userspace is larger than the amount of memory actually allocated >> in userspace and passed in the 'from' parameter: >> >> [ 1549.080032] NMI watchdog: BUG: soft lockup - CPU#11 stuck for 22s! [trinity-c11:12699] >> [ 1549.080032] Modules linked in: >> [ 1549.080032] hardirqs last enabled at (4202427): restore_args (arch/x86/kernel/entry_64.S:750) >> [ 1549.080032] hardirqs last disabled at (4202428): apic_timer_interrupt (arch/x86/kernel/entry_64.S:890) >> [ 1549.080032] softirqs last enabled at (4202426): __do_softirq (./arch/x86/include/asm/preempt.h:22 kernel/softirq.c:300) >> [ 1549.080032] softirqs last disabled at (4202421): irq_exit (kernel/softirq.c:350 kernel/softirq.c:391) >> [ 1549.080032] CPU: 11 PID: 12699 Comm: trinity-c11 Not tainted 4.0.0-rc6-next-20150402-sasha-00039-ge0bdae3-dirty #2125 >> [ 1549.080032] task: ffff880260f30000 ti: ffff88025ebe8000 task.ti: ffff88025ebe8000 >> [ 1549.080032] RIP: copy_user_handle_tail (arch/x86/lib/usercopy_64.c:85) >> [ 1549.080032] RSP: 0000:ffff88025ebefe38 EFLAGS: 00010202 >> [ 1549.080032] RAX: 00000000356cb494 RBX: 1ffff1004bd7dfcb RCX: 0000000000000000 > > Wow, that's some serious len in %rax. Almost a gigabyte AFAICT. Yup, you can load (or, the kernel would allow you to attempt and load) a module of up to 4GB in size. >> [ 1549.080032] RDX: 000000009277d652 RSI: ffffc90078bba001 RDI: ffffc90078bba000 > > Btw, what's happening to that user pointer in %rdi, is it kosher? Probably not. Trinity passes random addresses into that syscall, so it's probably one of it's magic values. > RSI: ffffc90078bba001 > RDI: ffffc90078bba000 > > Hohumm, @from and @to overlap by a byte... Interesting... > >> [ 1549.080032] RBP: ffff88025ebefe38 R08: 0000000000000000 R09: 0000000002f75001 >> [ 1549.080032] R10: 0000000000000000 R11: 0000000000000000 R12: ffff88025ebefe78 >> [ 1549.080032] R13: ffff88025ebeff18 R14: 0000000094949494 R15: 0000000000da91be >> [ 1549.080032] FS: 00007f1f669df700(0000) GS:ffff8803f2800000(0000) knlGS:0000000000000000 >> [ 1549.080032] CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b >> [ 1549.080032] CR2: 0000000002f75000 CR3: 000000025d031000 CR4: 00000000000007a0 >> [ 1549.080032] Stack: >> [ 1549.080032] ffff88025ebeff48 ffffffff963c5ef0 ffffc9001993c000 0000000000da91be >> [ 1549.080032] 0000000041b58ab3 ffffffffa32918f3 ffffffff963c5da0 0000000000000286 >> [ 1549.080032] ffffc9001993c000 0000000094949494 0000000000000000 0000000000000000 >> [ 1549.080032] Call Trace: >> [ 1549.080032] SyS_init_module (kernel/module.c:2505 kernel/module.c:3401 kernel/module.c:3388) >> [ 1549.080032] ? load_module (kernel/module.c:3388) >> [ 1549.080032] ia32_do_call (arch/x86/ia32/ia32entry.S:501) >> [ 1549.080032] Code: d0 66 66 90 8a 06 66 66 90 45 85 c0 74 d3 85 c9 74 23 89 d0 45 31 c0 eb 08 83 e8 01 48 89 f7 74 14 48 8d 77 01 44 89 c1 66 66 90 07 00 66 66 90 85 c9 74 e4 89 d0 66 66 90 5d c3 0f 1f 44 00 >> All code >> ======== >> 0: d0 66 66 shlb 0x66(%rsi) >> 3: 90 nop >> 4: 8a 06 mov (%rsi),%al >> 6: 66 66 90 data32 xchg %ax,%ax >> 9: 45 85 c0 test %r8d,%r8d >> c: 74 d3 je 0xffffffffffffffe1 >> e: 85 c9 test %ecx,%ecx >> 10: 74 23 je 0x35 >> 12: 89 d0 mov %edx,%eax >> 14: 45 31 c0 xor %r8d,%r8d >> 17: eb 08 jmp 0x21 >> 19: 83 e8 01 sub $0x1,%eax >> 1c: 48 89 f7 mov %rsi,%rdi >> 1f: 74 14 je 0x35 >> 21: 48 8d 77 01 lea 0x1(%rdi),%rsi >> 25: 44 89 c1 mov %r8d,%ecx >> 28: 66 66 90 data32 xchg %ax,%ax >> 2b:* c6 07 00 movb $0x0,(%rdi) <-- trapping instruction >> 2e: 66 66 90 data32 xchg %ax,%ax >> 31: 85 c9 test %ecx,%ecx >> 33: 74 e4 je 0x19 >> 35: 89 d0 mov %edx,%eax >> 37: 66 66 90 data32 xchg %ax,%ax >> 3a: 5d pop %rbp >> 3b: c3 retq >> 3c: 0f 1f 44 00 00 nopl 0x0(%rax,%rax,1) > > Hmm, lotsa alternatives patching around that area even though I can't > see anything wrong from looking at your dump. The "66 66 90" nops are > the STAC/CLAC things optimized to NOPs which are asm volatile within the > __put_user_asm()'s own asm volatile. And I thought the labels might be > fudged but my usercopy_64.s version here looks ok. > > Can you boot that box with "debug-alternative" and send me dmesg? Also, > vmlinux too please. Privately's fine too. I've attached dmesg with debug-alternative, and my .config. vmlinux is pretty large (1GB compressed) so hopefully the config would be enough - let me know if it isn't. >> Code starting with the faulting instruction >> =========================================== >> 0: c6 07 00 movb $0x0,(%rdi) >> 3: 66 66 90 data32 xchg %ax,%ax >> 6: 85 c9 test %ecx,%ecx >> 8: 74 e4 je 0xffffffffffffffee >> a: 89 d0 mov %edx,%eax >> c: 66 66 90 data32 xchg %ax,%ax >> f: 5d pop %rbp >> 10: c3 retq >> 11: 0f 1f 44 00 00 nopl 0x0(%rax,%rax,1) >> >> >> This is the result of getting copy_user_handle_tail to zero out a large block of >> kernel memory very inefficiently: >> >> for (c = 0, zero_len = len; zerorest && zero_len; --zero_len) > > Btw, that zerorest is being tested on every loop iteration! AFAICT, > > if (!zerorest) { > clac(); > return len; > } > > before the loop should be nicer. Or am I missing something? Looks good to me. I suspect the compiler optimizes that anyway though. Thanks, Sasha