lkml.org 
[lkml]   [2012]   [Nov]   [2]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
From
SubjectPROBLEM: log: task flush-x:y:z blocked for more than 120 seconds: leading to unusable (stalled) machine
Description: On a desktop machine running an ArchLinux stock kernel, after 1/2 day uptime, while working under KDE SC, two I/O intensive tasks running for hours, I get a log message like
"INFO: task flush-254:0:539 blocked for more than 120 seconds."
and afterwards, the machine starts getting unusable, making it even impossible to get a working console session.
The situation can be reproduced with different kernel versions, but needs lots of patience to do so.

# cat /proc/version
Linux version 3.6.4-1-ARCH (tobias@T-POWA-LX) (gcc version 4.7.2 (GCC) ) #1 SMP PREEMPT Mon Oct 29 09:49:00 CET 2012

Log output:
Oct 28 06:11:46 daywalker kernel: [15120.660024] INFO: task flush-254:0:539 blocked for more than 120 seconds.
Oct 28 06:11:46 daywalker kernel: [15120.660329] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Oct 28 06:11:46 daywalker kernel: [15120.660675] flush-254:0 D ffffc900054b0000 0 539 2 0x00000000
Oct 28 06:11:46 daywalker kernel: [15120.660679] ffff88011f3294f0 0000000000000046 ffff88011f329770 ffff880120c25f80
Oct 28 06:11:46 daywalker kernel: [15120.660682] ffff88011f147710 ffff88011f329fd8 ffff88011f329fd8 ffff88011f329fd8
Oct 28 06:11:46 daywalker kernel: [15120.660685] ffff8800828607f0 ffff88011f147710 ffff88011f3294b8 0000000000000000
Oct 28 06:11:46 daywalker kernel: [15120.660688] Call Trace:
Oct 28 06:11:46 daywalker kernel: [15120.660696] [<ffffffff8117e1a7>] ? unlock_buffer+0x17/0x20
Oct 28 06:11:46 daywalker kernel: [15120.660699] [<ffffffff8117e1ec>] ? ll_rw_block+0x3c/0xc0
Oct 28 06:11:46 daywalker kernel: [15120.660718] [<ffffffffa00d8633>] ? search_by_key+0x103/0xfd0 [reiserfs]
Oct 28 06:11:46 daywalker kernel: [15120.660723] [<ffffffff81417381>] ? __mutex_lock_slowpath+0x211/0x2c0
Oct 28 06:11:46 daywalker kernel: [15120.660725] [<ffffffff81415f5f>] schedule+0x3f/0x60
Oct 28 06:11:46 daywalker kernel: [15120.660730] [<ffffffffa00dc3bc>] queue_log_writer+0x8c/0xd0 [reiserfs]
Oct 28 06:11:46 daywalker kernel: [15120.660734] [<ffffffff81051000>] ? try_to_wake_up+0x2d0/0x2d0
Oct 28 06:11:46 daywalker kernel: [15120.660739] [<ffffffffa00e2298>] do_journal_begin_r+0x248/0x410 [reiserfs]
Oct 28 06:11:46 daywalker kernel: [15120.660745] [<ffffffffa00d954d>] ? search_for_position_by_key+0x4d/0xa0 [reiserfs]
Oct 28 06:11:46 daywalker kernel: [15120.660750] [<ffffffffa00e24f7>] journal_begin+0x97/0x160 [reiserfs]
Oct 28 06:11:46 daywalker kernel: [15120.660755] [<ffffffffa00e2636>] reiserfs_persistent_transaction+0x76/0xd0 [reiserfs]
Oct 28 06:11:46 daywalker kernel: [15120.660760] [<ffffffffa00c79ab>] reiserfs_get_block+0x85b/0x1120 [reiserfs]
Oct 28 06:11:46 daywalker kernel: [15120.660767] [<ffffffffa0e2ab68>] ? __map_bio+0x48/0x150 [dm_mod]
Oct 28 06:11:46 daywalker kernel: [15120.660772] [<ffffffffa00d80d6>] ? search_for_position_by_key.part.14+0xc6/0x1f0 [reiserfs]
Oct 28 06:11:46 daywalker kernel: [15120.660777] [<ffffffffa00c846b>] map_block_for_writepage+0x13b/0x620 [reiserfs]
Oct 28 06:11:46 daywalker kernel: [15120.660781] [<ffffffff8113f4fc>] ? kmem_cache_alloc+0x10c/0x120
Oct 28 06:11:46 daywalker kernel: [15120.660786] [<ffffffffa00c8a82>] reiserfs_writepage+0x132/0x5e0 [reiserfs]
Oct 28 06:11:46 daywalker kernel: [15120.660789] [<ffffffff810fdaba>] __writepage+0x1a/0x50
Oct 28 06:11:46 daywalker kernel: [15120.660792] [<ffffffff810fdf8e>] write_cache_pages+0x1de/0x490
Oct 28 06:11:46 daywalker kernel: [15120.660794] [<ffffffff810fdaa0>] ? bdi_set_max_ratio+0x90/0x90
Oct 28 06:11:46 daywalker kernel: [15120.660797] [<ffffffff810fe28d>] generic_writepages+0x4d/0x70
Oct 28 06:11:46 daywalker kernel: [15120.660799] [<ffffffff810ff0bd>] do_writepages+0x3d/0x50
Oct 28 06:11:46 daywalker kernel: [15120.660802] [<ffffffff81176ebf>] writeback_single_inode+0xef/0x270
Oct 28 06:11:46 daywalker kernel: [15120.660804] [<ffffffff8117729f>] writeback_sb_inodes+0xef/0x1a0
Oct 28 06:11:46 daywalker kernel: [15120.660807] [<ffffffff8117811c>] writeback_inodes_wb+0x8c/0x160
Oct 28 06:11:46 daywalker kernel: [15120.660809] [<ffffffff811784f0>] wb_writeback+0x300/0x400
Oct 28 06:11:46 daywalker kernel: [15120.660811] [<ffffffff81178808>] wb_do_writeback+0x218/0x220
Oct 28 06:11:46 daywalker kernel: [15120.660814] [<ffffffff81178893>] bdi_writeback_thread+0x83/0x250
Oct 28 06:11:46 daywalker kernel: [15120.660816] [<ffffffff81178810>] ? wb_do_writeback+0x220/0x220
Oct 28 06:11:46 daywalker kernel: [15120.660819] [<ffffffff8107b99c>] kthread+0x8c/0xa0
Oct 28 06:11:46 daywalker kernel: [15120.660821] [<ffffffff81421364>] kernel_thread_helper+0x4/0x10
Oct 28 06:11:46 daywalker kernel: [15120.660824] [<ffffffff8107b910>] ? kthread_worker_fn+0x1b0/0x1b0
Oct 28 06:11:46 daywalker kernel: [15120.660826] [<ffffffff81421360>] ? gs_change+0x13/0x13
Oct 28 06:11:46 daywalker kernel: [15120.660835] INFO: task kded4:710 blocked for more than 120 seconds.
...

# cat /proc/cpuinfo
processor : 0
vendor_id : AuthenticAMD
cpu family : 15
model : 67
model name : AMD Athlon(tm) 64 X2 Dual Core Processor 6000+
stepping : 3
cpu MHz : 1000.000
cache size : 1024 KB
physical id : 0
siblings : 2
core id : 0
cpu cores : 2
apicid : 0
initial apicid : 0
fpu : yes
fpu_exception : yes
cpuid level : 1
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt rdtscp lm 3dnowext 3dnow rep_good nopl pni cx16 lahf_lm cmp_legacy svm extapic cr8_legacy
bogomips : 2009.71
TLB size : 1024 4K pages
clflush size : 64
cache_alignment : 64
address sizes : 40 bits physical, 48 bits virtual
power management: ts fid vid ttp tm stc

processor : 1
vendor_id : AuthenticAMD
cpu family : 15
model : 67
model name : AMD Athlon(tm) 64 X2 Dual Core Processor 6000+
stepping : 3
cpu MHz : 1000.000
cache size : 1024 KB
physical id : 0
siblings : 2
core id : 1
cpu cores : 2
apicid : 1
initial apicid : 1
fpu : yes
fpu_exception : yes
cpuid level : 1
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt rdtscp lm 3dnowext 3dnow rep_good nopl pni cx16 lahf_lm cmp_legacy svm extapic cr8_legacy
bogomips : 2009.71
TLB size : 1024 4K pages
clflush size : 64
cache_alignment : 64
address sizes : 40 bits physical, 48 bits virtual
power management: ts fid vid ttp tm stc

# cat /proc/modules
vboxdrv 1823469 0 - Live 0xffffffffa0fe1000 (O)
cbc 2736 2 - Live 0xffffffffa014a000
xts 3101 1 - Live 0xffffffffa02d7000
gf128mul 6050 1 xts, Live 0xffffffffa0393000
dm_crypt 15799 3 - Live 0xffffffffa038b000
dm_mod 72105 7 dm_crypt, Live 0xffffffffa036f000
sha256_generic 10261 4 - Live 0xffffffffa02f6000
sha1_generic 2323 0 - Live 0xffffffffa025d000
aes_x86_64 7508 6 - Live 0xffffffffa0243000
aes_generic 26138 1 aes_x86_64, Live 0xffffffffa0365000
squashfs 27579 0 - Live 0xffffffffa029e000
uhci_hcd 23436 0 - Live 0xffffffffa0292000
snd_hda_codec_hdmi 24487 1 - Live 0xffffffffa0230000
nvidia 11215270 50 - Live 0xffffffffa052d000 (PO)
joydev 9991 0 - Live 0xffffffffa019e000
usb_storage 47320 0 - Live 0xffffffffa0358000
uas 11119 0 - Live 0xffffffffa00d8000
snd_hda_codec_realtek 61065 1 - Live 0xffffffffa02e1000
r8169 56839 0 - Live 0xffffffffa02c6000
forcedeth 56097 0 - Live 0xffffffffa02b7000
psmouse 71909 0 - Live 0xffffffffa027f000
mii 4091 1 r8169, Live 0xffffffffa0193000
i2c_nforce2 5071 0 - Live 0xffffffffa0258000
serio_raw 4689 0 - Live 0xffffffffa0240000
dcdbas 5520 0 - Live 0xffffffffa0238000
powernow_k8 13373 1 - Live 0xffffffffa018b000
mperf 1267 1 powernow_k8, Live 0xffffffffa000e000
thermal 8119 0 - Live 0xffffffffa00ca000
snd_hda_intel 26180 5 - Live 0xffffffffa0520000
snd_hda_codec 98033 3 snd_hda_codec_hdmi,snd_hda_codec_realtek,snd_hda_intel, Live 0xffffffffa04d2000
snd_hwdep 6300 1 snd_hda_codec, Live 0xffffffffa04cc000
snd_pcm 75167 3 snd_hda_codec_hdmi,snd_hda_intel,snd_hda_codec, Live 0xffffffffa048c000
fan 2618 0 - Live 0xffffffffa0488000
kvm_amd 52187 0 - Live 0xffffffffa0462000
k8temp 3378 0 - Live 0xffffffffa045e000
snd_page_alloc 7217 2 snd_hda_intel,snd_pcm, Live 0xffffffffa044d000
i2c_core 20707 2 nvidia,i2c_nforce2, Live 0xffffffffa043a000
snd_timer 18934 1 snd_pcm, Live 0xffffffffa0420000
edac_core 42566 0 - Live 0xffffffffa0404000
edac_mce_amd 12277 0 - Live 0xffffffffa03fd000
evdev 10266 21 - Live 0xffffffffa03ef000
kvm 373917 1 kvm_amd, Live 0xffffffffa02fb000
pcspkr 1899 0 - Live 0xffffffffa0195000
button 4662 0 - Live 0xffffffffa02f3000
processor 26855 1 powernow_k8, Live 0xffffffffa02d9000
snd 59989 17 snd_hda_codec_hdmi,snd_hda_codec_realtek,snd_hda_intel,snd_hda_codec,snd_hwdep,snd_pcm,snd_timer, Live 0xffffffffa02a7000
soundcore 5442 1 snd, Live 0xffffffffa0154000
nfs 126943 0 - Live 0xffffffffa025f000
lockd 64840 1 nfs, Live 0xffffffffa0247000
sunrpc 186249 2 nfs,lockd, Live 0xffffffffa0201000
fscache 40995 1 nfs, Live 0xffffffffa01f5000
hid_generic 1113 0 - Live 0xffffffffa000a000
usbhid 36996 0 - Live 0xffffffffa01ea000
hid 85929 2 hid_generic,usbhid, Live 0xffffffffa01d4000
ohci_hcd 21784 0 - Live 0xffffffffa011c000
ehci_hcd 41816 0 - Live 0xffffffffa01c8000
usbcore 150398 6 uhci_hcd,usb_storage,uas,usbhid,ohci_hcd,ehci_hcd, Live 0xffffffffa01a2000
usb_common 954 1 usbcore, Live 0xffffffffa0006000
sr_mod 14823 0 - Live 0xffffffffa0145000
pata_amd 11502 0 - Live 0xffffffffa0118000
cdrom 35520 1 sr_mod, Live 0xffffffffa00ce000
sd_mod 29559 7 - Live 0xffffffffa00c1000
sata_nv 21327 5 - Live 0xffffffffa0197000
libata 167683 2 pata_amd,sata_nv, Live 0xffffffffa0158000
scsi_mod 133386 5 usb_storage,uas,sr_mod,sd_mod,libata, Live 0xffffffffa0123000
reiserfs 239918 2 - Live 0xffffffffa00dc000
btrfs 718537 1 - Live 0xffffffffa0010000
crc32c 1768 1 - Live 0xffffffffa000c000
libcrc32c 1002 1 btrfs, Live 0xffffffffa0008000
zlib_deflate 20436 1 btrfs, Live 0xffffffffa0000000



Klaus-J. Wolf
kernelbug@arcor.de


\
 
 \ /
  Last update: 2012-11-03 01:41    [W:0.045 / U:0.252 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site