Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1755652AbcCUNpY (ORCPT ); Mon, 21 Mar 2016 09:45:24 -0400 Received: from mail-wm0-f51.google.com ([74.125.82.51]:36941 "EHLO mail-wm0-f51.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1754479AbcCUNpV (ORCPT ); Mon, 21 Mar 2016 09:45:21 -0400 MIME-Version: 1.0 In-Reply-To: <15565.1458436494@turing-police.cc.vt.edu> References: <7300.1458333684@turing-police.cc.vt.edu> <15565.1458436494@turing-police.cc.vt.edu> Date: Mon, 21 Mar 2016 14:45:18 +0100 Message-ID: Subject: Re: KASAN overhead? From: Alexander Potapenko To: Valdis Kletnieks Cc: Linux Memory Management List , LKML , Andrey Ryabinin Content-Type: multipart/mixed; boundary=001a1130c848b448b7052e8f4e32 Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Length: 5073 Lines: 112 --001a1130c848b448b7052e8f4e32 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable On Sun, Mar 20, 2016 at 2:14 AM, wrote: > On Sat, 19 Mar 2016 13:13:59 +0100, Alexander Potapenko said: > >> Which GCC version were you using? Are you sure it didn't accidentally >> enable the outline instrumentation (e.g. if the compiler is too old)? > > gcc --version > gcc (GCC) 6.0.0 20160311 (Red Hat 6.0.0-0.16) > > * Fri Mar 11 2016 Jakub Jelinek 6.0.0-0.15 > - update from the trunk > > Doesn't get much newer than that.. :) (Hmm.. possibly *too* new?) Fine,this one should be new enough. >> > and saw an *amazing* slowdown. >> Have you tried earlier KASAN versions? Is this a recent regression? > > First time I'd tried it, so no comparison point.. > >> Was KASAN reporting anything between these lines? Sometimes a recurring >> warning slows everything down. > > Nope, it didn't report a single thing. > >> How did it behave after the startup? Was it still slow? > > After seeing how long it took to get to a single-user prompt, I didn't > investigate further. It took 126 seconds to get here: > > [ 126.937247] audit: type=3D1327 audit(1458268293.617:100): proctitle=3D= "/usr/sbin/sulogin" > > compared to the more usual: > > [ 29.249260] audit: type=3D1327 audit(1458326938.276:100): proctitle=3D= "/usr/sbin/sulogin" > > (In both cases, there's a 10-12 second pause for entering a LUKS > passphrase, so we're looking at about 110 seconds with KASAN versus > about 17-18 without.) > >> Which machine were you using? Was it a real device or a VM? > > Running native on a Dell Latitude laptop.... > > (Based on the fact that you're asking questions rather than just saying > it's expected behavior, I'm guessing I've once again managed to find > a corner case of some sort. I'm more than happy to troubleshoot, if > you can provide hints of what to try...) On my machine the kernel startup times with and without KASAN are mostly similar (8.4 vs. 6.2 seconds), but I don't think the startup times actually reflect anything. First, they depend heavily on the kernel configuration, and second, the percentage of time spent in the kernel during startup is greater than that during normal operation. With the attached benchmark (which is far from being ideal, but may give some idea about the slowdown) I'm seeing the slowdown factor of around 2.5x, which is more realistic. --=20 Alexander Potapenko Software Engineer Google Germany GmbH Erika-Mann-Stra=C3=9Fe, 33 80636 M=C3=BCnchen Gesch=C3=A4ftsf=C3=BChrer: Matthew Scott Sucherman, Paul Terence Manicle Registergericht und -nummer: Hamburg, HRB 86891 Sitz der Gesellschaft: Hamburg --001a1130c848b448b7052e8f4e32 Content-Type: text/x-csrc; charset=US-ASCII; name="bench_pipes.c" Content-Disposition: attachment; filename="bench_pipes.c" Content-Transfer-Encoding: base64 X-Attachment-Id: f_im21o5xd1 I2luY2x1ZGUgPHVuaXN0ZC5oPgojaW5jbHVkZSA8c3lzL3R5cGVzLmg+CiNpbmNsdWRlIDxzdGRs aWIuaD4KI2luY2x1ZGUgPHN0ZGlvLmg+CiNpbmNsdWRlIDxlcnJuby5oPgojaW5jbHVkZSA8cHRo cmVhZC5oPgoKCnN0YXRpYyBpbnQgbnBpcGVzID0gMTsKc3RhdGljIGludCBuaXRlcnMgPSAxOwoK CnZvaWQgKmRvX3BpcGVzKHZvaWQqIHVudXNlZCk7CgppbnQgbWFpbihpbnQgYXJnYywgY2hhciAq KmFyZ3YpIHsKCWludCBudGhyZWFkcyA9IDE7CglwdGhyZWFkX3QgKnRocmVhZHM7CglwdGhyZWFk X2F0dHJfdCBhdHRyOwoJaW50IHJjID0gMDsKCWludCBpOwoJaWYgKGFyZ2MgPCAyKSB7CgkJcHJp bnRmKCJVc2FnZTogJXMgPG5waXBlcz4gPG5pdGVycz4gPG50aHJlYWRzPlxuIiwgYXJndlswXSk7 CgkJcmV0dXJuIDE7Cgl9CglucGlwZXMgPSBhdG9pKGFyZ3ZbMV0pOwoJaWYgKGFyZ2MgPj0gMykg CgkJbml0ZXJzID0gYXRvaShhcmd2WzJdKTsKCWlmIChhcmdjID49IDQpCgkJbnRocmVhZHMgPSBh dG9pKGFyZ3ZbM10pOwoJCglwdGhyZWFkX2F0dHJfaW5pdCgmYXR0cik7CglwdGhyZWFkX2F0dHJf c2V0ZGV0YWNoc3RhdGUoJmF0dHIsIFBUSFJFQURfQ1JFQVRFX0pPSU5BQkxFKTsKCXRocmVhZHMg PSBtYWxsb2Moc2l6ZW9mKHB0aHJlYWRfdCkgKiBudGhyZWFkcyk7Cglmb3IgKGkgPSAwOyBpIDwg bnRocmVhZHM7IGkrKykgewoJCXJjID0gcHRocmVhZF9jcmVhdGUoJnRocmVhZHNbaV0sICZhdHRy LCAmZG9fcGlwZXMsIE5VTEwpOwoJCWlmIChyYykgewoJCQlwcmludGYoIkNvdWxkbid0IHN0YXJ0 IHRocmVhZC4gZXJyb3IgJWRcbiIsIHJjKTsKCQkJcmV0dXJuIC0xOwkKCQl9Cgl9CglwdGhyZWFk X2F0dHJfZGVzdHJveSgmYXR0cik7Cglmb3IgKGkgPSAwOyBpIDwgbnRocmVhZHM7IGkrKykgewoJ CXJjID0gcHRocmVhZF9qb2luKHRocmVhZHNbaV0sIE5VTEwpOwoJCWlmIChyYykgewoJCQlwcmlu dGYoIkNvdWxkbid0IGpvaW4gdGhyZWFkLiBlcnJvciAlZFxuIiwgcmMpOwoJCQlyZXR1cm4gLTE7 CQoJCX0KCX0KCWZyZWUodGhyZWFkcyk7CglwdGhyZWFkX2V4aXQoTlVMTCk7Cn0KCnZvaWQgKmRv X3BpcGVzKHZvaWQqIHVudXNlZCkgewoJaW50KiBwaXBlczsKCWludCBpLGo7CgljaGFyIGMgPSAn YSc7CglwaXBlcyA9IG1hbGxvYyhzaXplb2YoaW50KSAqIG5waXBlcyAqIDIpOwoJZm9yIChqID0g MDsgaiA8IG5pdGVyczsgKytqKSB7CgkJZm9yIChpID0gMDsgaSA8IG5waXBlczsgKytpKSB7CgkJ CWlmIChwaXBlKCZwaXBlc1tpICogMl0pKSB7CgkJCQlwZXJyb3IoIkNvdWxkbid0IG9wZW4gcGlw ZSIpOwoJCQkJZnJlZShwaXBlcyk7CgkJCQlleGl0KC0xKTsKCQkJfQoJCS8vCXdyaXRlKHBpcGVz W2kgKiAyICsgMV0sICZjLCAxKTsKCQl9CgkJZm9yIChpID0gMDsgaSA8IG5waXBlczsgKytpKSB7 CgkJLy8JcmVhZChwaXBlc1tpICogMl0sICZjLCAxKTsKCQkJY2xvc2UocGlwZXNbaSAqIDJdKTsK CQkJY2xvc2UocGlwZXNbaSAqIDIgKyAxXSk7CgkJfQoJfQoJZnJlZShwaXBlcyk7CglwdGhyZWFk X2V4aXQodW51c2VkKTsKfQo= --001a1130c848b448b7052e8f4e32--