Bug#516374: task mysqld:30918 blocked for more than 120 seconds.

[Paul Sohier <paul@paulsohier.nl>]

Hi,

Iam currently experiencing this as well on a VM, running KVM on a host. 
Only running mysql, currently pretty low usage, but this evening, with a 
pretty large query and it looks with pretty high I/O it was caused this 
bug with the next messages in dmesg:

[669930.073036] INFO: task mysqld:30918 blocked for more than 120 seconds.
[669930.073836] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" 
disables this message.
[669930.075216] mysqld        D 0000000000000000     0 30918   7210
[669930.075221]  ffff810009801b38 0000000000000086 0000000000000000 
ffff81005a7f4a80
[669930.075226]  ffff810009929120 ffff81007fb9d470 ffff8100099293a8 
0000000100000004
[669930.075229]  0000000000000004 0000000000000000 00000000ffffffff 
0000000000000000
[669930.075232] Call Trace:
[669930.075254]  [<ffffffffa00eb6f8>] :jbd:do_get_write_access+0x1d7/0x3be
[669930.075260]  [<ffffffff8024622f>] wake_bit_function+0x0/0x23
[669930.075266]  [<ffffffff802ba74a>] __getblk+0x1d/0x206
[669930.075275]  [<ffffffffa00eb901>] 
:jbd:journal_get_write_access+0x22/0x33
[669930.075288]  [<ffffffffa0108f25>] 
:ext3:__ext3_journal_get_write_access+0x1e/0x47
[669930.075298]  [<ffffffffa00fcc1d>] 
:ext3:ext3_reserve_inode_write+0x3d/0x76
[669930.075302]  [<ffffffff80246201>] autoremove_wake_function+0x0/0x2e
[669930.075311]  [<ffffffffa00fcc6c>] :ext3:ext3_mark_inode_dirty+0x16/0x31
[669930.075322]  [<ffffffffa00ff8ab>] :ext3:ext3_dirty_inode+0x63/0x7b
[669930.075337]  [<ffffffff802b6d78>] __mark_inode_dirty+0x29/0x179
[669930.075343]  [<ffffffff802adb37>] touch_atime+0x109/0x112
[669930.075348]  [<ffffffff80272d8b>] generic_file_aio_read+0x446/0x4ae
[669930.075358]  [<ffffffff8029ae23>] do_sync_read+0xc9/0x10c
[669930.075364]  [<ffffffff80246201>] autoremove_wake_function+0x0/0x2e
[669930.075370]  [<ffffffff8023b63d>] cap_set_effective+0x1d/0x51
[669930.075377]  [<ffffffff8021f26e>] pvclock_clocksource_read+0x3a/0x71
[669930.075383]  [<ffffffff8029b614>] vfs_read+0xaa/0x152
[669930.075387]  [<ffffffff8029b9f5>] sys_read+0x45/0x6e
[669930.075392]  [<ffffffff8020beca>] system_call_after_swapgs+0x8a/0x8f
[669930.075397]

Using the latest lenny kernel:
mysql:~# uname -a
Linux mysql 2.6.26-2-amd64 #1 SMP Thu Nov 5 02:23:12 UTC 2009 x86_64 
GNU/Linux

If someone has a solution, it would be really nice.

Regards,
Paul Sohier.