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
(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?

Thanks.

--
tejun


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