From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1759230AbZBSWAA (ORCPT ); Thu, 19 Feb 2009 17:00:00 -0500 Received: (majordomo@vger.kernel.org) by vger.kernel.org id S1756619AbZBSV7v (ORCPT ); Thu, 19 Feb 2009 16:59:51 -0500 Received: from ey-out-2122.google.com ([74.125.78.27]:4469 "EHLO ey-out-2122.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1754339AbZBSV7v (ORCPT ); Thu, 19 Feb 2009 16:59:51 -0500 MIME-Version: 1.0 In-Reply-To: References: <1234722028-8110-1-git-send-email-andr345@gmail.com> <200902182227.14686.rusty@rustcorp.com.au> <200902192145.10616.rusty@rustcorp.com.au> Date: Thu, 19 Feb 2009 22:59:48 +0100 Message-ID: Subject: Re: [RFC PATCH 0/6] module, kbuild: Faster boot with custom kernel. From: Kay Sievers To: Rusty Russell Cc: Andreas Robinson , sam@ravnborg.org, linux-kernel@vger.kernel.org, Jon Masters Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 7bit Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On Thu, Feb 19, 2009 at 21:48, Kay Sievers wrote: > On Thu, Feb 19, 2009 at 12:41, Kay Sievers wrote: >> On Thu, Feb 19, 2009 at 12:15, Rusty Russell wrote: >>> On Thursday 19 February 2009 00:27:58 Kay Sievers wrote: >>>> some modules wait for 200-500 milliseconds to >>>> get the lock released, some larger modules spend 50 milliseconds in >>>> load_module(), many of them around 20 milliseconds. >>> >>> OK, this is an untested hack (don't try unloading modules, not sure symbol >>> resolution isn't racy now I've killed the lock). Does it change the numbers? >> >> That changes it dramatically. The numbers from the sycall until the >> linked-in module are now down to 15-25 milliseconds, and for a few >> large modules 50-100. >> >> (One crazy exception is ipv6, which takes 620 milliseconds to link, no >> idea what it needs to do.) > > Sorry, this was caused by I/O wait from disk for that huge module, and > gets to reasonable numbers by putting all modules into RAM before > loading them. > >> I'll compare a few bootup times with and without the patch, and come >> back later today with the real numbers. > > The whole massive parallel modprobe happens during udev coldplug. I > tried a 2GHz Dual Core laptop, and a setup without initramfs here, > which loads ~40 modules. All the kernel modules are copied to a ramfs > mount before the coldplug is started. > > I measured the time from the first modprobe that happened in the > kernel to the loading of "dummy", which I manually trigger from the > udev boot script, and which gets called right after udev has settled > and handled all events. > > With the mutex it takes 1.8 seconds, without it, it takes 1.3 seconds. > If I comment out the creation of the stop_machine() threads, it gets > down to 1.1 seconds. > > With the mutex, I see code waiting for up to 180 milliseconds waiting > for the mutex, the average between 20-40 milliseconds. > > Without the mutex the largest time to link is 30 milliseconds, and > most of them are around 5-10 milliseconds. > > Without the mutex and the stop_machine() creation, the flow of tracing > output looks like real work and, depending on the actual module, they > spend time in various stages of linking, relocation and so on, there > are no long delays for any of the modules, like I see with the current > code. > > It would be great, if we can safely minimize the time spent in the mutex. Further testing revealed, if I only comment out the stop_machine() preparation, which is used in an error case, I get almost the same improvement, even with the original mutex in place. Without the mutex it's still a bit better, maybe it would be much better if we have more CPUs, but all the long delays are gone only with removing the stop_machine() preparation. Thanks, Kay