Ubuntu
linux package

kworkerd busy for about 10s in bootcharts, slowing boot

Bug #721389 reported by Hernando Torque on 2011-02-18

This bug affects 1 person

Affects		Status	Importance	Assigned to	Milestone
	linux (Ubuntu)	Fix Released	Medium	Andy Whitcroft

Bug Description

Starting with 2.6.38-rc1 I see a boot time increase of almost 50%. The boot charts show two processes in an unusual long uninterruptible sleep state: plymouthd and kworker/*:* (see attached images). It's happening with a Nvidia GPU as well as with an on-die Intel HD GPU (hybrid graphics solution in a ThinkPad T510).

Bisecting the kernel between 2.6.37 and 2.6.38-rc1 showed this merge as first bad commit: http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commit;h=23d69b09b78c4876e134f104a3814c30747c53f1

(I have yet to find the problematic commit within that merge.)

ProblemType: Bug
DistroRelease: Ubuntu 11.04
Package: linux-image-2.6.38-4-generic 2.6.38-4.31
Regression: Yes
Reproducible: Yes
ProcVersionSignature: Ubuntu 2.6.38-4.31-generic 2.6.38-rc5
Uname: Linux 2.6.38-4-generic x86_64
AlsaVersion: Advanced Linux Sound Architecture Driver Version 1.0.23.
Architecture: amd64
ArecordDevices:
**** List of CAPTURE Hardware Devices ****
card 0: Intel [HDA Intel], device 0: CONEXANT Analog [CONEXANT Analog]
   Subdevices: 1/1
   Subdevice #0: subdevice #0
AudioDevicesInUse:
USER PID ACCESS COMMAND
/dev/snd/controlC0: sirius 1330 F.... pulseaudio
CRDA: Error: [Errno 2] No such file or directory
Card0.Amixer.info:
Card hw:0 'Intel'/'HDA Intel at 0xf2600000 irq 43'
   Mixer name : 'Intel IbexPeak HDMI'
   Components : 'HDA:14f15069,17aa218b,00100302 HDA:80862804,17aa21b5,00100000'
   Controls : 12
   Simple ctrls : 6
Card29.Amixer.info:
Card hw:29 'ThinkPadEC'/'ThinkPad Console Audio Control at EC reg 0x30, fw 6MHT42WW-1.17'
   Mixer name : 'ThinkPad EC 6MHT42WW-1.17'
   Components : ''
   Controls : 1
   Simple ctrls : 1
Card29.Amixer.values:
Simple mixer control 'Console',0
   Capabilities: pswitch pswitch-joined penum
   Playback channels: Mono
   Mono: Playback [on]
Date: Fri Feb 18 17:51:20 2011
HibernationDevice: RESUME=UUID=c70ee7d5-a3aa-40bc-9625-a297c3c1eea2
InstallationMedia: Ubuntu 11.04 "Natty Narwhal" - Alpha amd64 (20110112)
Lsusb:
Bus 002 Device 002: ID 8087:0020 Intel Corp. Integrated Rate Matching Hub
Bus 002 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 001 Device 002: ID 8087:0020 Intel Corp. Integrated Rate Matching Hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
MachineType: LENOVO 4349WK7
ProcEnviron:
LANGUAGE=en_US:en
PATH=(custom, user)
LANG=en_US.UTF-8
LC_MESSAGES=en_US.utf8
SHELL=/bin/bash
ProcKernelCmdLine: BOOT_IMAGE=/boot/vmlinuz-2.6.38-4-generic root=UUID=755daaa3-ddf9-4451-ad6d-2b5354cee2c2 ro quiet splash elevator=deadline bootchart=disable vt.handoff=7
RelatedPackageVersions:
linux-restricted-modules-2.6.38-4-generic N/A
linux-backports-modules-2.6.38-4-generic N/A
linux-firmware 1.47
RfKill:
0: phy0: Wireless LAN
  Soft blocked: no
  Hard blocked: no
SourcePackage: linux
dmi.bios.date: 09/29/2010
dmi.bios.vendor: LENOVO
dmi.bios.version: 6MET75WW (1.35 )
dmi.board.name: 4349WK7
dmi.board.vendor: LENOVO
dmi.board.version: Not Available
dmi.chassis.asset.tag: No Asset Information
dmi.chassis.type: 10
dmi.chassis.vendor: LENOVO
dmi.chassis.version: Not Available
dmi.modalias: dmi:bvnLENOVO:bvr6MET75WW(1.35):bd09/29/2010:svnLENOVO:pn4349WK7:pvrThinkPadT510:rvnLENOVO:rn4349WK7:rvrNotAvailable:cvnLENOVO:ct10:cvrNotAvailable:
dmi.product.name: 4349WK7
dmi.product.version: ThinkPad T510
dmi.sys.vendor: LENOVO

Tags:

Revision history for this message

Hernando Torque (htorque) wrote on 2011-02-18:

last ubuntu kernel without the regression Edit (231.4 KiB, image/png)
AcpiTables.txt Edit (336.6 KiB, text/plain; charset="utf-8")
AlsaDevices.txt Edit (587 bytes, text/plain; charset="utf-8")
AplayDevices.txt Edit (261 bytes, text/plain; charset="utf-8")
BootDmesg.txt Edit (55.7 KiB, text/plain; charset="utf-8")
Card0.Amixer.values.txt Edit (1.1 KiB, text/plain; charset="utf-8")
Card0.Codecs.codec.0.txt Edit (8.1 KiB, text/plain; charset="utf-8")
Card0.Codecs.codec.3.txt Edit (2.7 KiB, text/plain; charset="utf-8")
CurrentDmesg.txt Edit (2.1 KiB, text/plain; charset="utf-8")
Dependencies.txt Edit (1.8 KiB, text/plain; charset="utf-8")
IwConfig.txt Edit (513 bytes, text/plain; charset="utf-8")
Lspci.txt Edit (12.3 KiB, text/plain; charset="utf-8")
PciMultimedia.txt Edit (598 bytes, text/plain; charset="utf-8")
ProcCpuinfo.txt Edit (3.3 KiB, text/plain; charset="utf-8")
ProcCpuinfo_.txt Edit (3.3 KiB, text/plain; charset="utf-8")
ProcInterrupts.txt Edit (1.8 KiB, text/plain; charset="utf-8")
ProcModules.txt Edit (2.4 KiB, text/plain; charset="utf-8")
UdevDb.txt Edit (100.4 KiB, text/plain; charset="utf-8")
UdevLog.txt Edit (246.8 KiB, text/plain; charset="utf-8")
WifiSyslog.txt Edit (1.8 MiB, text/plain; charset="utf-8")

Revision history for this message

Hernando Torque (htorque) wrote on 2011-02-18:

current ubuntu kernel showing the regression (plymouthd/kworker processes) Edit (228.6 KiB, image/png)

Revision history for this message

Hernando Torque (htorque) wrote on 2011-02-22:

This is now being discussed at https://lkml.org/lkml/2011/2/22/78

Revision history for this message

Hernando Torque (htorque) wrote on 2011-02-23:

The culprit has been found and a patch prepared for upstream application: https://lkml.org/lkml/2011/2/23/103

Revision history for this message

Hernando Torque (htorque) wrote on 2011-02-24:

http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commit;h=1d64b655dc083df5c5ac39945ccbbc6532903bf1

Changed in linux (Ubuntu):
status:	New → Fix Committed

Revision history for this message

Andy Whitcroft (apw) wrote on 2011-02-24:

The fix is upstream, not committed to our sources as yet.

Changed in linux (Ubuntu):
status:	Fix Committed → In Progress

Revision history for this message

Andy Whitcroft (apw) wrote on 2011-02-24:

This is the upstream commit:

  commit 1d64b655dc083df5c5ac39945ccbbc6532903bf1
  Author: Dmitry Torokhov <email address hidden>
  Date: Wed Feb 23 08:51:28 2011 -0800

Input: serio/gameport - use 'long' system workqueue

    Commit 8ee294cd9def0004887da7f44b80563493b0a097 converted serio
    subsystem event handling from using a dedicated thread to using
    common workqueue. Unfortunately, this regressed our boot times,
    due to the fact that serio jobs take long time to execute. While
    the new concurrency managed workqueue code manages long-playing
    works just fine and schedules additional workers as needed, such
    works wreck havoc among remaining users of flush_scheduled_work().

To solve this problem let's move serio/gameport works from system_wq
to system_long_wq which nobody tries to flush.

    Reported-and-tested-by: Hernando Torque <email address hidden>
    Acked-by: Tejun Heo <email address hidden>
    Signed-off-by: Dmitry Torokhov <email address hidden>

Revision history for this message

Andy Whitcroft (apw) wrote on 2011-02-24:

Ok I have pulled that specifc commit back to a Natty kernel and build test kernels. Could you confirm that the kernels below also fix your boot regression:

http://people.canonical.com/~apw/lp721389-natty/

Please report back here. Thanks.

tags:	added: kernel-key
summary:	- Boot time regression 2.6.38 + Boot time regression 2.6.38 -- kworkerd busy for in bootcharts
summary:	- Boot time regression 2.6.38 -- kworkerd busy for in bootcharts + kworkerd busy for about 10s in bootcharts, slowing boot

Revision history for this message

Andy Whitcroft (apw) wrote on 2011-02-24:

Changing the title to be more specific, to prevent dogpiling.

Changed in linux (Ubuntu):
importance:	Undecided → Medium

Revision history for this message

Andy Whitcroft (apw) wrote on 2011-02-24:

#10

Boot speed is important, but this does seem to be restricted to specific hardware. Does not exhibit on any of my machines.

Revision history for this message

Hernando Torque (htorque) wrote on 2011-02-24:

#11

Yes, working fine with that kernel.

Maybe this only happens with ThinkPad TrackPoints? Just a wild guess from the dump_stack() output: http://paste.ubuntu.com/570729/ Also, it's probably not that noticeable with non-SSD systems.

Revision history for this message

Andy Whitcroft (apw) wrote on 2011-02-28:

#12

pulled in the proposed fix, for the next upload.

Changed in linux (Ubuntu):
assignee:	nobody → Andy Whitcroft (apw)
status:	In Progress → Fix Committed

Revision history for this message

Launchpad Janitor (janitor) wrote on 2011-03-07:

#13

This bug was fixed in the package linux - 2.6.38-6.33

---------------
linux (2.6.38-6.33) natty; urgency=low

[ Andy Whitcroft ]

  * d-i -- enable speakup-modules udeb
    - LP: #672699
  * rebase to 493f3358cb289ccf716c5a14fa5bb52ab75943e5
  * [Config] debian PPC64 configuration
  * [Config] cleanup powerpc config fixing unexpected inconsistancies
  * [Config] resync ppc64 configuration
  * SAUCE: match up ENTRY/END naming for 32/64 bit
  * rebase to fb62c00a6d8942775abc23d1621db1252e2d93d1
  * [Config] update configs after rebase to
    fb62c00a6d8942775abc23d1621db1252e2d93d1
  * [Config] pps_gen_parport no longer built

[ Corentin Chary ]

  * SAUCE: (drop after 2.6.38) eeepc-wmi: reorder keymap
    - LP: #689393
  * SAUCE: (drop after 2.6.38) eeepc-wmi: add wlan key found on 1015P
    - LP: #689393

[ John Johansen ]

* SAUCE: Fix aufs calling of security_path_mknod
- LP: #724456

[ Kees Cook ]

* SAUCE: proc: hide kernel addresses via %pK in /proc/<pid>/stack

[ Tim Gardner ]

* rebase to 2.6.38-rc7

[ Upstream Kernel Changes ]

* Revert "drm/i915: fix corruptions on i8xx due to relaxed fencing"

[ Major Kernel Changes ]

  * rebase from v2.6.38-rc6 to v2.6.38-rc7 +
    fb62c00a6d8942775abc23d1621db1252e2d93d1
    - LP: #721389
    - LP: #722925
    - LP: #723672
    - LP: #723676
    - LP: #715318
-- Andy Whitcroft <email address hidden> Mon, 07 Mar 2011 15:33:17 +0000

Changed in linux (Ubuntu):
status:	Fix Committed → Fix Released

Report a bug

This report contains Public information

Everyone can see this information.

You are

Subscribing...

Edit bug mail

Other bug subscribers

Bug attachments

Add attachment

Remote bug watches

Bug watches keep track of this bug in other bug trackers.

Ubuntulinux package

kworkerd busy for about 10s in bootcharts, slowing boot

Bug Description

Other bug subscribers

Bug attachments

Remote bug watches

Ubuntu
linux package