Messages in this thread | | | Date | Tue, 22 Feb 2011 00:52:23 -0800 | From | Dmitry Torokhov <> | Subject | Re: Boot time regression in 2.6.38 after initial wq merge |
| |
On Tue, Feb 22, 2011 at 09:17:52AM +0100, Tejun Heo wrote: > (cc'ing Dmitry and lkml) > > Hello, > > On Mon, Feb 21, 2011 at 09:44:12PM +0100, pantherchen@versanet.de wrote: > > I'm experiencing a significant boot time regression (almost +50%) > > starting with 2.6.38-rc1 (see boot charts before [0], and after [1] > > - note the long uninterruptible sleep of kworker/0:1). > > Comparing the two boot charts, the uninterruptible sleeps in > kowrker/0:1 seems to be the same one from kseriod. They're about the > same duration. kseriod is replaced with a work item, so that explains > it. > > > After doing some bisecting and thorough testing this merge seems to > > be the first one showing the regression: http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commit;h=23d69b09b78c4876e134f104a3814c30747c53f1 > > ("Merge branch 'for-2.6.38' of > > git://git.kernel.org/pub/scm/linux/kernel/git/tj/wq"). > > > > However, a kernel built from the branch 'for-2.6.38' at > > git://git.kernel.org/pub/scm/linux/kernel/git/tj/wq doesn't show the > > behavior. > > > > I also tried to cherry-pick those 33 commits, applying them to the > > last good commit from Linus' tree (http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commit;h=4ead36407b41eae942c8c9f70ef963cd369c90e2) > > and it also doesn't show the regression. > > > > Do you know what's going on here? I'm just an end user and I've > > definitely run out of ideas. > > > > Thanks in advance for your help, > > > > Hernando Torque > > Thanks > > > > [0]: http://launchpadlibrarian.net/64639927/27-12-intel.png > > [1]: http://launchpadlibrarian.net/64640030/38-4-intel.png > > From the boot chart, two things are noticeable. > > 1. kworker/0:1's uninterruptible sleeps start later than kserio's. > > It could be that cpu 0 was busy running other stuff and thus cmwq > delayed executing serio_event_work; however, if we look at the CPU > usage, that doesn't seem likely. The CPU is not busy at all and if > the CPU isn't busy, cmwq wouldn't introduce any noticeable delay in > work item execution. > > Another possibility is the rescuer concurrency depletion bug is > delaying execution of queued work items early during boot. This > was fixed recently. Can you please give a shot at 2.6.38-rc6 and > see whether anything is different? > > 2. Most of the delay is caused by xorg starting up much later. xorg > seems to start up in parallel with the kseriod sleeps in 2.6.37 but > on 2.6.38 it seems to wait for the serio_event_work to finish. > > I have no idea what xorg is waiting for. Dmitry, any clue? >
It looks like it is not X is waiting but plymouth not being told to quit... I will have to look at waht triggers plymouth->X/GDM transition.
Also, serio jobs (mouse probe) is quite lengthtly. Should it be using unbound workqueue instead?
Thanks.
-- Dmitry
| |