Bug 66161

Summary:	many application blocked
Product:	File System	Reporter:	Alexander Osipenko (korvin2000)
Component:	ext3	Assignee:	fs_ext3 (fs_ext3)
Status:	RESOLVED INSUFFICIENT_DATA
Severity:	normal	CC:	alan, jack
Priority:	P1
Hardware:	x86-64
OS:	Linux
Kernel Version:	3.12.1	Subsystem:
Regression:	No	Bisected commit-id:

Description Alexander Osipenko 2013-11-29 19:06:33 UTC

[  480.344037] INFO: task jsvc:4327 blocked for more than 120 seconds.
[  480.344083]       Not tainted 3.12.1 #1
[  480.344106] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  480.344150] jsvc            D ffff8800c91c8040     0  4327   2849 0x00000000
[  480.344154]  ffff8800c91c8040 0000000000000086 ffff8800c9a9c140 ffff880224315e80
[  480.344157]  0000000000012e80 ffff880224315fd8 ffff880224315fd8 ffff8800c91c8040
[  480.344160]  0000000000000246 ffff880223c72000 0000000000b6a483 ffff880224315e80
[  480.344162] Call Trace:
[  480.344183]  [<ffffffffa00a850f>] ? log_wait_commit+0xe5/0x152 [jbd]
[  480.344188]  [<ffffffff81051081>] ? wake_up_atomic_t+0x22/0x22
[  480.344195]  [<ffffffffa016cac6>] ? ext3_sync_file+0x13a/0x1d0 [ext3]
[  480.344199]  [<ffffffff811289fb>] ? do_fsync+0x2b/0x50
[  480.344201]  [<ffffffff81128bf7>] ? SyS_fsync+0x9/0xe
[  480.344205]  [<ffffffff8137f9e2>] ? system_call_fastpath+0x16/0x1b
[  480.344246] INFO: task asterisk:4683 blocked for more than 120 seconds.
[  480.344284]       Not tainted 3.12.1 #1
[  480.344308] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  480.344352] asterisk        D ffff8800c9ac9140     0  4683      1 0x00000000
[  480.344355]  ffff8800c9ac9140 0000000000000086 ffff88008e5b30c0 ffff88022529fe80
[  480.344358]  0000000000012e80 ffff88022529ffd8 ffff88022529ffd8 ffff8800c9ac9140
[  480.344360]  0000000000000246 ffff880223c72000 0000000000b6a483 ffff88022529fe80
[  480.344362] Call Trace:
[  480.344367]  [<ffffffffa00a850f>] ? log_wait_commit+0xe5/0x152 [jbd]
[  480.344370]  [<ffffffff81051081>] ? wake_up_atomic_t+0x22/0x22
[  480.344375]  [<ffffffffa016cac6>] ? ext3_sync_file+0x13a/0x1d0 [ext3]
[  480.344377]  [<ffffffff811289fb>] ? do_fsync+0x2b/0x50
[  480.344379]  [<ffffffff81128bf7>] ? SyS_fsync+0x9/0xe
[  480.344381]  [<ffffffff8137f9e2>] ? system_call_fastpath+0x16/0x1b
[  480.344388] INFO: task asterisk:5377 blocked for more than 120 seconds.
[  480.344426]       Not tainted 3.12.1 #1
[  480.344450] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  480.344494] asterisk        D ffff88022fc92e80     0  5377      1 0x00000000
[  480.344496]  ffff88008e677870 0000000000000086 ffff880036ea8870 ffff88008e4d3e20
[  480.344499]  0000000000012e80 ffff88008e4d3fd8 ffff88008e4d3fd8 ffff88008e677870
[  480.344501]  0000000000000246 ffff880223c72000 0000000000b6a483 ffff88008e4d3e20
[  480.344503] Call Trace:
[  480.344508]  [<ffffffffa00a850f>] ? log_wait_commit+0xe5/0x152 [jbd]
[  480.344511]  [<ffffffff81051081>] ? wake_up_atomic_t+0x22/0x22
[  480.344515]  [<ffffffffa00a3aaf>] ? journal_stop+0x1e8/0x21e [jbd]
[  480.344520]  [<ffffffffa016cb38>] ? ext3_sync_file+0x1ac/0x1d0 [ext3]
[  480.344522]  [<ffffffff811289fb>] ? do_fsync+0x2b/0x50
[  480.344524]  [<ffffffff81128bf7>] ? SyS_fsync+0x9/0xe
[  480.344526]  [<ffffffff8137f9e2>] ? system_call_fastpath+0x16/0x1b
[  480.344536] INFO: task cleanup:6727 blocked for more than 120 seconds.
[  480.344575]       Not tainted 3.12.1 #1
[  480.344597] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  480.344641] cleanup         D ffff8801bd369040     0  6727   6700 0x00000000
[  480.344644]  ffff8801bd369040 0000000000000086 ffff880226ca60c0 ffff88008e7cbe80
[  480.344646]  0000000000012e80 ffff88008e7cbfd8 ffff88008e7cbfd8 ffff8801bd369040
[  480.344648]  0000000000000246 ffff880223c72000 0000000000b6a484 ffff88008e7cbe80
[  480.344651] Call Trace:
[  480.344656]  [<ffffffffa00a850f>] ? log_wait_commit+0xe5/0x152 [jbd]
[  480.344658]  [<ffffffff81051081>] ? wake_up_atomic_t+0x22/0x22
[  480.344663]  [<ffffffffa016cac6>] ? ext3_sync_file+0x13a/0x1d0 [ext3]
[  480.344665]  [<ffffffff811289fb>] ? do_fsync+0x2b/0x50
[  480.344668]  [<ffffffff81105381>] ? SyS_fchmod+0x4a/0x67
[  480.344670]  [<ffffffff81128bf7>] ? SyS_fsync+0x9/0xe
[  480.344673]  [<ffffffff8137f9e2>] ? system_call_fastpath+0x16/0x1b

Comment 1 Alan 2013-12-03 15:20:10 UTC

All blocked on the filesystem. Not enough info in the log sections pasted to be sure of the root cause but it looks like a disk stopped responding and everything then backed up waiting for writes to complete.

Moving to fs/ext3

Comment 2 Jan Kara 2013-12-04 13:11:00 UTC

Yeah, is this reproducible? If yes, can you do 'echo w >/proc/sysrq-trigger' and attach full kernel log here (output of dmesg command) please? Thanks.

Comment 3 Alexander Osipenko 2013-12-04 13:21:39 UTC

i upgrade to Linux lineage.m3x.org 3.13.0-rc2 #1 SMP Sat Nov 30 01:58:21 EET 2013 x86_64 GNU/Linux and not have problem this time

Comment 4 Jan Kara 2013-12-10 23:24:24 UTC

OK, closing the bug. Since I'm not aware of any fix in this area, I'm just making this bug 'INSUFFICIENT_DATA'