Ubuntu

kworkerd busy for about 10s in bootcharts, slowing boot

Reported by Hernando Torque on 2011-02-18
8
This bug affects 1 person
Affects Status Importance Assigned to Milestone
linux (Ubuntu)
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

Hernando Torque (htorque) wrote :
Hernando Torque (htorque) wrote :

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

Hernando Torque (htorque) wrote :

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

Andy Whitcroft (apw) wrote :

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

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

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>

Andy Whitcroft (apw) wrote :

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
Andy Whitcroft (apw) wrote :

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

Changed in linux (Ubuntu):
importance: Undecided → Medium
Andy Whitcroft (apw) wrote :

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

Hernando Torque (htorque) wrote :

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.

Andy Whitcroft (apw) wrote :

pulled in the proposed fix, for the next upload.

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

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
To post a comment you must log in.