lkml.org 
[lkml]   [2011]   [Feb]   [22]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
From
SubjectRe: 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


\
 
 \ /
  Last update: 2011-02-22 09:55    [W:0.049 / U:0.220 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site