Is anyone else seeing issues relating to memory fragmentation and IO
starved processes?
The machine concerned is a backup server - so it rsyncs data from other
servers, and attempts to write data to tape. So it does some heavy IO,
and memory is full of data saved as disk cache. But this memory should
be reclaimable. Why, when it has vast areas of reclaimable memory, does
the kernel not ensure it keeps some reserves of contiguous memory to
satisfy these sorts of requests?
I've read all about patches to linux kernel which supposedly fix memory
fragmentation issues - but, they just don't seem to be working in SL6 (I
have even tried the recent elrepo kernels, based on 2.6.39, and if
anything, they are worse than the standard SL6 kernel)
How, with all the work that has gone into IO schedulers can generating a
file list for rsync (ioniced to a low priority!!) cause tasks like tar
to block for more than 120 seconds - on a fast disk array, Adaptec 51245
raid controller with 10x3Tb drives, properly striped/strided, formatted
as two ext4 volumes. The array is blindingly fast under usual
circumstances, but, give it contention from several processes performing
IO, and suddenly the OS is starving one of them for long periods. I have
even seen the jbd journalling process starved to such an extent it
cannot keep the journal up to date on the disk volumes!!! What sort of
disk scheduling algorithm is this!?
Any advice on what might be going on here would be appreciated! - should
it really be necessary to delve into tuning vm system parameters just to
avoid memory fragmentation causing device drivers and system calls to
fail? To be messing around trying different vm paramaters just to make a
machine usable doesn't seem to make sense.
Example of memory fragmentation problems:
Nov 16 02:16:11 phoenix kernel: mount.nfs4: page allocation failure.
order:4, mode:0xd0
Nov 16 02:16:11 phoenix kernel: Pid: 32280, comm: mount.nfs4 Tainted: G
---------------- T 2.6.32-131.4.1.el6.x86_64 #1
Nov 16 02:16:11 phoenix kernel: Call Trace:
Nov 16 02:16:11 phoenix kernel: [<ffffffff81120126>] ?
__alloc_pages_nodemask+0x716/0x8b0
Nov 16 02:16:11 phoenix kernel: [<ffffffff811597b2>] ?
kmem_getpages+0x62/0x170
Nov 16 02:16:11 phoenix kernel: [<ffffffff8115a3ca>] ?
fallback_alloc+0x1ba/0x270
Nov 16 02:16:11 phoenix kernel: [<ffffffff81159e1f>] ?
cache_grow+0x2cf/0x320
Nov 16 02:16:11 phoenix kernel: [<ffffffff8115a149>] ?
____cache_alloc_node+0x99/0x160
Nov 16 02:16:11 phoenix kernel: [<ffffffff8115a95a>] ?
kmem_cache_alloc_notrace+0xfa/0x130
Nov 16 02:16:11 phoenix kernel: [<ffffffffa0587787>] ?
nfs_idmap_new+0x37/0x160 [nfs]
Nov 16 02:16:11 phoenix kernel: [<ffffffff81269d6a>] ? strlcpy+0x4a/0x60
Nov 16 02:16:11 phoenix kernel: [<ffffffffa055155e>] ?
nfs4_set_client+0xfe/0x2f0 [nfs]
Nov 16 02:16:11 phoenix kernel: [<ffffffffa0551801>] ?
nfs_alloc_server+0xb1/0x140 [nfs]
Nov 16 02:16:11 phoenix kernel: [<ffffffffa0552333>] ?
nfs4_create_server+0xd3/0x350 [nfs]
Nov 16 02:16:11 phoenix kernel: [<ffffffffa055dc30>] ?
nfs4_remote_get_sb+0xa0/0x2c0 [nfs]
Nov 16 02:16:11 phoenix kernel: [<ffffffff811753eb>] ?
vfs_kern_mount+0x7b/0x1b0
Nov 16 02:16:11 phoenix kernel: [<ffffffffa055eb3f>] ?
nfs_do_root_mount+0x7f/0xb0 [nfs]
Nov 16 02:16:11 phoenix kernel: [<ffffffffa055ec82>] ?
nfs4_try_mount+0x52/0xd0 [nfs]
Nov 16 02:16:11 phoenix kernel: [<ffffffffa055eda2>] ?
nfs4_get_sb+0xa2/0x340 [nfs]
Nov 16 02:16:11 phoenix kernel: [<ffffffff811753eb>] ?
vfs_kern_mount+0x7b/0x1b0
Nov 16 02:16:11 phoenix kernel: [<ffffffff81175592>] ?
do_kern_mount+0x52/0x130
Nov 16 02:16:11 phoenix kernel: [<ffffffff81193067>] ?
do_mount+0x2e7/0x870
Nov 16 02:16:11 phoenix kernel: [<ffffffff81190b42>] ?
copy_mount_options+0xf2/0x1a0
Nov 16 02:16:11 phoenix kernel: [<ffffffff81193680>] ?
sys_mount+0x90/0xe0
Nov 16 02:16:11 phoenix kernel: [<ffffffff8100b172>] ?
system_call_fastpath+0x16/0x1b
Nov 16 02:16:11 phoenix kernel: Mem-Info:
Nov 16 02:16:11 phoenix kernel: Node 0 DMA per-cpu:
Nov 16 02:16:11 phoenix kernel: CPU 0: hi: 0, btch: 1 usd: 0
Nov 16 02:16:11 phoenix kernel: CPU 1: hi: 0, btch: 1 usd: 0
Nov 16 02:16:11 phoenix kernel: CPU 2: hi: 0, btch: 1 usd: 0
Nov 16 02:16:11 phoenix kernel: CPU 3: hi: 0, btch: 1 usd: 0
Nov 16 02:16:11 phoenix kernel: CPU 4: hi: 0, btch: 1 usd: 0
Nov 16 02:16:11 phoenix kernel: CPU 5: hi: 0, btch: 1 usd: 0
Nov 16 02:16:11 phoenix kernel: CPU 6: hi: 0, btch: 1 usd: 0
Nov 16 02:16:11 phoenix kernel: CPU 7: hi: 0, btch: 1 usd: 0
Nov 16 02:16:11 phoenix kernel: Node 0 DMA32 per-cpu:
Nov 16 02:16:11 phoenix kernel: CPU 0: hi: 186, btch: 31 usd: 93
Nov 16 02:16:11 phoenix kernel: CPU 1: hi: 186, btch: 31 usd: 0
Nov 16 02:16:11 phoenix kernel: CPU 2: hi: 186, btch: 31 usd: 0
Nov 16 02:16:11 phoenix kernel: CPU 3: hi: 186, btch: 31 usd: 0
Nov 16 02:16:11 phoenix kernel: CPU 4: hi: 186, btch: 31 usd: 0
Nov 16 02:16:11 phoenix kernel: CPU 5: hi: 186, btch: 31 usd: 0
Nov 16 02:16:11 phoenix kernel: CPU 6: hi: 186, btch: 31 usd: 0
Nov 16 02:16:11 phoenix kernel: CPU 7: hi: 186, btch: 31 usd: 0
Nov 16 02:16:11 phoenix kernel: Node 0 Normal per-cpu:
Nov 16 02:16:11 phoenix kernel: CPU 0: hi: 186, btch: 31 usd: 0
Nov 16 02:16:11 phoenix kernel: CPU 1: hi: 186, btch: 31 usd: 0
Nov 16 02:16:11 phoenix kernel: CPU 2: hi: 186, btch: 31 usd: 0
Nov 16 02:16:11 phoenix kernel: CPU 3: hi: 186, btch: 31 usd: 0
Nov 16 02:16:11 phoenix kernel: CPU 4: hi: 186, btch: 31 usd: 0
Nov 16 02:16:11 phoenix kernel: CPU 5: hi: 186, btch: 31 usd: 0
Nov 16 02:16:11 phoenix kernel: CPU 6: hi: 186, btch: 31 usd: 0
Nov 16 02:16:11 phoenix kernel: CPU 7: hi: 186, btch: 31 usd: 0
Nov 16 02:16:11 phoenix kernel: active_anon:122772 inactive_anon:26310
isolated_anon:0
Nov 16 02:16:11 phoenix kernel: active_file:521706 inactive_file:650943
isolated_file:0
Nov 16 02:16:11 phoenix kernel: unevictable:0 dirty:8822 writeback:12
unstable:0
Nov 16 02:16:11 phoenix kernel: free:33404 slab_reclaimable:548666
slab_unreclaimable:67241
Nov 16 02:16:11 phoenix kernel: mapped:9269 shmem:1047 pagetables:5793
bounce:0
Nov 16 02:16:11 phoenix kernel: Node 0 DMA free:15652kB min:124kB
low:152kB high:184kB active_anon:0kB inactive_anon:0kB active_file:0kB
inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB
present:15232kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB
slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB
pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0
all_unreclaimable? no
Nov 16 02:16:11 phoenix kernel: lowmem_reserve[]: 0 2653 7953 7953
Nov 16 02:16:11 phoenix kernel: Node 0 DMA32 free:56756kB min:22500kB
low:28124kB high:33748kB active_anon:140916kB inactive_anon:52388kB
active_file:683384kB inactive_file:850468kB unevictable:0kB
isolated(anon):0kB isolated(file):0kB present:2716836kB mlocked:0kB
dirty:7532kB writeback:92kB mapped:1288kB shmem:0kB
slab_reclaimable:640120kB slab_unreclaimable:19700kB kernel_stack:80kB
pagetables:640kB unstable:0kB bounce:0kB writeback_tmp:0kB
pages_scanned:76 all_unreclaimable? no
Nov 16 02:16:11 phoenix kernel: lowmem_reserve[]: 0 0 5300 5300
Nov 16 02:16:11 phoenix kernel: Node 0 Normal free:61208kB min:44952kB
low:56188kB high:67428kB active_anon:350172kB inactive_anon:52852kB
active_file:1403440kB inactive_file:1753304kB unevictable:0kB
isolated(anon):0kB isolated(file):0kB present:5427740kB mlocked:0kB
dirty:27756kB writeback:0kB mapped:35788kB shmem:4188kB
slab_reclaimable:1554544kB slab_unreclaimable:249264kB
kernel_stack:3400kB pagetables:22532kB unstable:0kB bounce:0kB
writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Nov 16 02:16:11 phoenix kernel: lowmem_reserve[]: 0 0 0 0
Nov 16 02:16:11 phoenix kernel: Node 0 DMA: 1*4kB 0*8kB 2*16kB 2*32kB
3*64kB 2*128kB 1*256kB 1*512kB 0*1024kB 1*2048kB 3*4096kB = 15652kB
Nov 16 02:16:11 phoenix kernel: Node 0 DMA32: 4559*4kB 4414*8kB 88*16kB
1*32kB 1*64kB 1*128kB 1*256kB 1*512kB 1*1024kB 0*2048kB 0*4096kB =
56972kB
Nov 16 02:16:11 phoenix kernel: Node 0 Normal: 12635*4kB 1355*8kB
12*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB
= 61572kB
Nov 16 02:16:11 phoenix kernel: 1173808 total pagecache pages
Nov 16 02:16:11 phoenix kernel: 0 pages in swap cache
Nov 16 02:16:11 phoenix kernel: Swap cache stats: add 0, delete 0, find
0/0
Nov 16 02:16:11 phoenix kernel: Free swap = 10485752kB
Nov 16 02:16:11 phoenix kernel: Total swap = 10485752kB
Nov 16 02:16:11 phoenix kernel: 2096624 pages RAM
Nov 16 02:16:11 phoenix kernel: 105383 pages reserved
Nov 16 02:16:11 phoenix kernel: 907263 pages shared
Nov 16 02:16:11 phoenix kernel: 1056570 pages non-shared
Below, an example log showing competing IO completely starving a tar
command...
Dec 14 09:03:19 phoenix kernel: INFO: task tar:14772 blocked for more
than 120 seconds.
Dec 14 09:03:19 phoenix kernel: "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dec 14 09:03:19 phoenix kernel: tar D 0000000000000002 0
14772 14657 0x00000080
Dec 14 09:03:19 phoenix kernel: ffff8801059d9c28 0000000000000082
0000000000000000 0000000000000000
Dec 14 09:03:19 phoenix kernel: ffff8801209350c0 000000018124eed1
ffff88023bfdd200 ffff880246304090
Dec 14 09:03:19 phoenix kernel: ffff880244ad50b8 ffff8801059d9fd8
000000000000f598 ffff880244ad50b8
Dec 14 09:03:19 phoenix kernel: Call Trace:
Dec 14 09:03:19 phoenix kernel: [<ffffffff814db5a5>]
schedule_timeout+0x215/0x2e0
Dec 14 09:03:19 phoenix kernel: [<ffffffff814db223>]
wait_for_common+0x123/0x180
Dec 14 09:03:19 phoenix kernel: [<ffffffff8105dc20>] ?
default_wake_function+0x0/0x20
Dec 14 09:03:19 phoenix kernel: [<ffffffff81247812>] ?
__generic_unplug_device+0x32/0x40
Dec 14 09:03:19 phoenix kernel: [<ffffffff814db33d>]
wait_for_completion+0x1d/0x20
Dec 14 09:03:19 phoenix kernel: [<ffffffffa03e74c3>]
st_do_scsi.clone.0+0x213/0x380 [st]
Dec 14 09:03:19 phoenix kernel: [<ffffffffa03ebf12>]
st_write+0x5a2/0xc70 [st]
Dec 14 09:03:19 phoenix kernel: [<ffffffff8108e100>] ?
autoremove_wake_function+0x0/0x40
Dec 14 09:03:19 phoenix kernel: [<ffffffff811725a8>]
vfs_write+0xb8/0x1a0
Dec 14 09:03:19 phoenix kernel: [<ffffffff81172fe1>] sys_write+0x51/0x90
Dec 14 09:03:19 phoenix kernel: [<ffffffff8100b172>]
system_call_fastpath+0x16/0x1b
Dec 14 09:05:19 phoenix kernel: INFO: task tar:14772 blocked for more
than 120 seconds.
Dec 14 09:05:19 phoenix kernel: "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dec 14 09:05:19 phoenix kernel: tar D 0000000000000002 0
14772 14657 0x00000080
Dec 14 09:05:19 phoenix kernel: ffff8801059d9c28 0000000000000082
0000000000000000 0000000000000000
Dec 14 09:05:19 phoenix kernel: ffff8801209350c0 000000018124eed1
ffff88023bfdd200 ffff880246304090
Dec 14 09:05:19 phoenix kernel: ffff880244ad50b8 ffff8801059d9fd8
000000000000f598 ffff880244ad50b8
Dec 14 09:05:19 phoenix kernel: Call Trace:
Dec 14 09:05:19 phoenix kernel: [<ffffffff814db5a5>]
schedule_timeout+0x215/0x2e0
Dec 14 09:05:19 phoenix kernel: [<ffffffff814db223>]
wait_for_common+0x123/0x180
Dec 14 09:05:19 phoenix kernel: [<ffffffff8105dc20>] ?
default_wake_function+0x0/0x20
Dec 14 09:05:19 phoenix kernel: [<ffffffff81247812>] ?
__generic_unplug_device+0x32/0x40
Dec 14 09:05:19 phoenix kernel: [<ffffffff814db33d>]
wait_for_completion+0x1d/0x20
Dec 14 09:05:19 phoenix kernel: [<ffffffffa03e74c3>]
st_do_scsi.clone.0+0x213/0x380 [st]
Dec 14 09:05:19 phoenix kernel: [<ffffffffa03ebf12>]
st_write+0x5a2/0xc70 [st]
Dec 14 09:05:19 phoenix kernel: [<ffffffff8108e100>] ?
autoremove_wake_function+0x0/0x40
Dec 14 09:05:19 phoenix kernel: [<ffffffff811725a8>]
vfs_write+0xb8/0x1a0
Dec 14 09:05:19 phoenix kernel: [<ffffffff81172fe1>] sys_write+0x51/0x90
Dec 14 09:05:19 phoenix kernel: [<ffffffff8100b172>]
system_call_fastpath+0x16/0x1b
Dec 14 09:05:19 phoenix kernel: INFO: task mtx:18835 blocked for more
than 120 seconds.
Dec 14 09:05:19 phoenix kernel: "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dec 14 09:05:19 phoenix kernel: mtx D 0000000000000006 0
18835 1 0x00000084
Dec 14 09:05:19 phoenix kernel: ffff8801e016bbf8 0000000000000086
0000000000000000 00000000000280da
Dec 14 09:05:19 phoenix kernel: ffff8801e016bc78 ffffffff8111fb21
ffff880000028d80 0000000103316746
Dec 14 09:05:19 phoenix kernel: ffff8802423d3038 ffff8801e016bfd8
000000000000f598 ffff8802423d3038
Dec 14 09:05:19 phoenix kernel: Call Trace:
Dec 14 09:05:19 phoenix kernel: [<ffffffff8111fb21>] ?
__alloc_pages_nodemask+0x111/0x8b0
Dec 14 09:05:19 phoenix kernel: [<ffffffff813545b5>]
scsi_block_when_processing_errors+0xd5/0x100
Dec 14 09:05:19 phoenix kernel: [<ffffffff8108e100>] ?
autoremove_wake_function+0x0/0x40
Dec 14 09:05:19 phoenix kernel: [<ffffffffa03dbfbe>] sg_open+0x23e/0x630
[sg]
Dec 14 09:05:19 phoenix kernel: [<ffffffff81264bfa>] ?
kobject_get+0x1a/0x30
Dec 14 09:05:19 phoenix kernel: [<ffffffff81175c31>] ?
cdev_get+0x31/0xe0
Dec 14 09:05:19 phoenix kernel: [<ffffffff811766d5>]
chrdev_open+0x125/0x230
Dec 14 09:05:19 phoenix kernel: [<ffffffff811765b0>] ?
chrdev_open+0x0/0x230
Dec 14 09:05:19 phoenix kernel: [<ffffffff8116f92a>]
__dentry_open+0x10a/0x360
Dec 14 09:05:19 phoenix kernel: [<ffffffff8120605f>] ?
security_inode_permission+0x1f/0x30
Dec 14 09:05:19 phoenix kernel: [<ffffffff8116fc94>]
nameidata_to_filp+0x54/0x70
Dec 14 09:05:19 phoenix kernel: [<ffffffff811828f0>]
do_filp_open+0x700/0xd90
Dec 14 09:05:19 phoenix kernel: [<ffffffff81041594>] ?
__do_page_fault+0x1e4/0x480
Dec 14 09:05:19 phoenix kernel: [<ffffffff81190f40>] ?
mntput_no_expire+0x30/0x110
Dec 14 09:05:19 phoenix kernel: [<ffffffff81173f31>] ?
__fput+0x1a1/0x210
Dec 14 09:05:19 phoenix kernel: [<ffffffff8118ef32>] ?
alloc_fd+0x92/0x160
Dec 14 09:05:19 phoenix kernel: [<ffffffff8116f6d9>]
do_sys_open+0x69/0x140
Dec 14 09:05:19 phoenix kernel: [<ffffffff8116f7f0>] sys_open+0x20/0x30
Dec 14 09:05:19 phoenix kernel: [<ffffffff8100b172>]
system_call_fastpath+0x16/0x1b
Dec 14 09:07:19 phoenix kernel: INFO: task tar:14772 blocked for more
than 120 seconds.
Dec 14 09:07:19 phoenix kernel: "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dec 14 09:07:19 phoenix kernel: tar D 0000000000000002 0
14772 14657 0x00000080
Dec 14 09:07:19 phoenix kernel: ffff8801059d9c28 0000000000000082
0000000000000000 0000000000000000
Dec 14 09:07:19 phoenix kernel: ffff8801209350c0 000000018124eed1
ffff88023bfdd200 ffff880246304090
Dec 14 09:07:19 phoenix kernel: ffff880244ad50b8 ffff8801059d9fd8
000000000000f598 ffff880244ad50b8
Dec 14 09:07:19 phoenix kernel: Call Trace:
Dec 14 09:07:19 phoenix kernel: [<ffffffff814db5a5>]
schedule_timeout+0x215/0x2e0
Dec 14 09:07:19 phoenix kernel: [<ffffffff814db223>]
wait_for_common+0x123/0x180
Dec 14 09:07:19 phoenix kernel: [<ffffffff8105dc20>] ?
default_wake_function+0x0/0x20
Dec 14 09:07:19 phoenix kernel: [<ffffffff81247812>] ?
__generic_unplug_device+0x32/0x40
Dec 14 09:07:19 phoenix kernel: [<ffffffff814db33d>]
wait_for_completion+0x1d/0x20
Dec 14 09:07:19 phoenix kernel: [<ffffffffa03e74c3>]
st_do_scsi.clone.0+0x213/0x380 [st]
Dec 14 09:07:19 phoenix kernel: [<ffffffffa03ebf12>]
st_write+0x5a2/0xc70 [st]
Dec 14 09:07:19 phoenix kernel: [<ffffffff8108e100>] ?
autoremove_wake_function+0x0/0x40
Dec 14 09:07:19 phoenix kernel: [<ffffffff811725a8>]
vfs_write+0xb8/0x1a0
Dec 14 09:07:19 phoenix kernel: [<ffffffff81172fe1>] sys_write+0x51/0x90
Dec 14 09:07:19 phoenix kernel: [<ffffffff8100b172>]
system_call_fastpath+0x16/0x1b
Dec 14 09:07:19 phoenix kernel: INFO: task mtx:18835 blocked for more
than 120 seconds.
Dec 14 09:07:19 phoenix kernel: "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dec 14 09:07:19 phoenix kernel: mtx D 0000000000000006 0
18835 1 0x00000084
Dec 14 09:07:19 phoenix kernel: ffff8801e016bbf8 0000000000000086
0000000000000000 00000000000280da
Dec 14 09:07:19 phoenix kernel: ffff8801e016bc78 ffffffff8111fb21
ffff880000028d80 0000000103316746
Dec 14 09:07:19 phoenix kernel: ffff8802423d3038 ffff8801e016bfd8
000000000000f598 ffff8802423d3038
Dec 14 09:07:19 phoenix kernel: Call Trace:
Dec 14 09:07:19 phoenix kernel: [<ffffffff8111fb21>] ?
__alloc_pages_nodemask+0x111/0x8b0
Dec 14 09:07:19 phoenix kernel: [<ffffffff813545b5>]
scsi_block_when_processing_errors+0xd5/0x100
Dec 14 09:07:19 phoenix kernel: [<ffffffff8108e100>] ?
autoremove_wake_function+0x0/0x40
Dec 14 09:07:19 phoenix kernel: [<ffffffffa03dbfbe>] sg_open+0x23e/0x630
[sg]
Dec 14 09:07:19 phoenix kernel: [<ffffffff81264bfa>] ?
kobject_get+0x1a/0x30
Dec 14 09:07:19 phoenix kernel: [<ffffffff81175c31>] ?
cdev_get+0x31/0xe0
Dec 14 09:07:19 phoenix kernel: [<ffffffff811766d5>]
chrdev_open+0x125/0x230
Dec 14 09:07:19 phoenix kernel: [<ffffffff811765b0>] ?
chrdev_open+0x0/0x230
Dec 14 09:07:19 phoenix kernel: [<ffffffff8116f92a>]
__dentry_open+0x10a/0x360
Dec 14 09:07:19 phoenix kernel: [<ffffffff8120605f>] ?
security_inode_permission+0x1f/0x30
Dec 14 09:07:19 phoenix kernel: [<ffffffff8116fc94>]
nameidata_to_filp+0x54/0x70
Dec 14 09:07:19 phoenix kernel: [<ffffffff811828f0>]
do_filp_open+0x700/0xd90
Dec 14 09:07:19 phoenix kernel: [<ffffffff81041594>] ?
__do_page_fault+0x1e4/0x480
Dec 14 09:07:19 phoenix kernel: [<ffffffff81190f40>] ?
mntput_no_expire+0x30/0x110
Dec 14 09:07:19 phoenix kernel: [<ffffffff81173f31>] ?
__fput+0x1a1/0x210
Dec 14 09:07:19 phoenix kernel: [<ffffffff8118ef32>] ?
alloc_fd+0x92/0x160
Dec 14 09:07:19 phoenix kernel: [<ffffffff8116f6d9>]
do_sys_open+0x69/0x140
Dec 14 09:07:19 phoenix kernel: [<ffffffff8116f7f0>] sys_open+0x20/0x30
Dec 14 09:07:19 phoenix kernel: [<ffffffff8100b172>]
system_call_fastpath+0x16/0x1b
Dec 14 09:07:19 phoenix kernel: INFO: task mtx:19095 blocked for more
than 120 seconds.
Dec 14 09:07:19 phoenix kernel: "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dec 14 09:07:19 phoenix kernel: mtx D 0000000000000004 0
19095 1 0x00000084
Dec 14 09:07:19 phoenix kernel: ffff88000f775bf8 0000000000000086
0000000000000000 00000000000280da
Dec 14 09:07:19 phoenix kernel: ffff88000f775c78 ffffffff8111fb21
ffff880000028d80 0000000103330135
Dec 14 09:07:19 phoenix kernel: ffff88024126bb38 ffff88000f775fd8
000000000000f598 ffff88024126bb38
Dec 14 09:07:19 phoenix kernel: Call Trace:
Dec 14 09:07:19 phoenix kernel: [<ffffffff8111fb21>] ?
__alloc_pages_nodemask+0x111/0x8b0
Dec 14 09:07:19 phoenix kernel: [<ffffffff813545b5>]
scsi_block_when_processing_errors+0xd5/0x100
Dec 14 09:07:19 phoenix kernel: [<ffffffff8108e100>] ?
autoremove_wake_function+0x0/0x40
Dec 14 09:07:19 phoenix kernel: [<ffffffffa03dbfbe>] sg_open+0x23e/0x630
[sg]
Dec 14 09:07:19 phoenix kernel: [<ffffffff81264bfa>] ?
kobject_get+0x1a/0x30
Dec 14 09:07:19 phoenix kernel: [<ffffffff81175c31>] ?
cdev_get+0x31/0xe0
Dec 14 09:07:19 phoenix kernel: [<ffffffff811766d5>]
chrdev_open+0x125/0x230
Dec 14 09:07:19 phoenix kernel: [<ffffffff811765b0>] ?
chrdev_open+0x0/0x230
Dec 14 09:07:19 phoenix kernel: [<ffffffff8116f92a>]
__dentry_open+0x10a/0x360
Dec 14 09:07:19 phoenix kernel: [<ffffffff8120605f>] ?
security_inode_permission+0x1f/0x30
Dec 14 09:07:19 phoenix kernel: [<ffffffff8116fc94>]
nameidata_to_filp+0x54/0x70
Dec 14 09:07:19 phoenix kernel: [<ffffffff811828f0>]
do_filp_open+0x700/0xd90
Dec 14 09:07:19 phoenix kernel: [<ffffffff81041594>] ?
__do_page_fault+0x1e4/0x480
Dec 14 09:07:19 phoenix kernel: [<ffffffff81190f40>] ?
mntput_no_expire+0x30/0x110
Dec 14 09:07:19 phoenix kernel: [<ffffffff81173f31>] ?
__fput+0x1a1/0x210
Dec 14 09:07:19 phoenix kernel: [<ffffffff8118ef32>] ?
alloc_fd+0x92/0x160
Dec 14 09:07:19 phoenix kernel: [<ffffffff8116f6d9>]
do_sys_open+0x69/0x140
Dec 14 09:07:19 phoenix kernel: [<ffffffff8116f7f0>] sys_open+0x20/0x30
Dec 14 09:07:19 phoenix kernel: [<ffffffff8100b172>]
system_call_fastpath+0x16/0x1b
Dec 14 09:09:19 phoenix kernel: INFO: task tar:14772 blocked for more
than 120 seconds.
Dec 14 09:09:19 phoenix kernel: "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dec 14 09:09:19 phoenix kernel: tar D 0000000000000002 0
14772 14657 0x00000080
Dec 14 09:09:19 phoenix kernel: ffff8801059d9c28 0000000000000082
0000000000000000 0000000000000000
Dec 14 09:09:19 phoenix kernel: ffff8801209350c0 000000018124eed1
ffff88023bfdd200 ffff880246304090
Dec 14 09:09:19 phoenix kernel: ffff880244ad50b8 ffff8801059d9fd8
000000000000f598 ffff880244ad50b8
Dec 14 09:09:19 phoenix kernel: Call Trace:
Dec 14 09:09:19 phoenix kernel: [<ffffffff814db5a5>]
schedule_timeout+0x215/0x2e0
Dec 14 09:09:19 phoenix kernel: [<ffffffff814db223>]
wait_for_common+0x123/0x180
Dec 14 09:09:19 phoenix kernel: [<ffffffff8105dc20>] ?
default_wake_function+0x0/0x20
Dec 14 09:09:19 phoenix kernel: [<ffffffff81247812>] ?
__generic_unplug_device+0x32/0x40
Dec 14 09:09:19 phoenix kernel: [<ffffffff814db33d>]
wait_for_completion+0x1d/0x20
Dec 14 09:09:19 phoenix kernel: [<ffffffffa03e74c3>]
st_do_scsi.clone.0+0x213/0x380 [st]
Dec 14 09:09:19 phoenix kernel: [<ffffffffa03ebf12>]
st_write+0x5a2/0xc70 [st]
Dec 14 09:09:19 phoenix kernel: [<ffffffff8108e100>] ?
autoremove_wake_function+0x0/0x40
Dec 14 09:09:19 phoenix kernel: [<ffffffff811725a8>]
vfs_write+0xb8/0x1a0
Dec 14 09:09:19 phoenix kernel: [<ffffffff81172fe1>] sys_write+0x51/0x90
Dec 14 09:09:19 phoenix kernel: [<ffffffff8100b172>]
system_call_fastpath+0x16/0x1b
Dec 14 09:09:19 phoenix kernel: INFO: task mtx:18835 blocked for more
than 120 seconds.
Dec 14 09:09:19 phoenix kernel: "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dec 14 09:09:19 phoenix kernel: mtx D 0000000000000006 0
18835 1 0x00000084
Dec 14 09:09:19 phoenix kernel: ffff8801e016bbf8 0000000000000086
0000000000000000 00000000000280da
Dec 14 09:09:19 phoenix kernel: ffff8801e016bc78 ffffffff8111fb21
ffff880000028d80 0000000103316746
Dec 14 09:09:19 phoenix kernel: ffff8802423d3038 ffff8801e016bfd8
000000000000f598 ffff8802423d3038
Dec 14 09:09:19 phoenix kernel: Call Trace:
Dec 14 09:09:19 phoenix kernel: [<ffffffff8111fb21>] ?
__alloc_pages_nodemask+0x111/0x8b0
Dec 14 09:09:19 phoenix kernel: [<ffffffff813545b5>]
scsi_block_when_processing_errors+0xd5/0x100
Dec 14 09:09:19 phoenix kernel: [<ffffffff8108e100>] ?
autoremove_wake_function+0x0/0x40
Dec 14 09:09:19 phoenix kernel: [<ffffffffa03dbfbe>] sg_open+0x23e/0x630
[sg]
Dec 14 09:09:19 phoenix kernel: [<ffffffff81264bfa>] ?
kobject_get+0x1a/0x30
Dec 14 09:09:19 phoenix kernel: [<ffffffff81175c31>] ?
cdev_get+0x31/0xe0
Dec 14 09:09:19 phoenix kernel: [<ffffffff811766d5>]
chrdev_open+0x125/0x230
Dec 14 09:09:19 phoenix kernel: [<ffffffff811765b0>] ?
chrdev_open+0x0/0x230
Dec 14 09:09:19 phoenix kernel: [<ffffffff8116f92a>]
__dentry_open+0x10a/0x360
Dec 14 09:09:19 phoenix kernel: [<ffffffff8120605f>] ?
security_inode_permission+0x1f/0x30
Dec 14 09:09:19 phoenix kernel: [<ffffffff8116fc94>]
nameidata_to_filp+0x54/0x70
Dec 14 09:09:19 phoenix kernel: [<ffffffff811828f0>]
do_filp_open+0x700/0xd90
Dec 14 09:09:19 phoenix kernel: [<ffffffff81041594>] ?
__do_page_fault+0x1e4/0x480
Dec 14 09:09:19 phoenix kernel: [<ffffffff81190f40>] ?
mntput_no_expire+0x30/0x110
Dec 14 09:09:19 phoenix kernel: [<ffffffff81173f31>] ?
__fput+0x1a1/0x210
Dec 14 09:09:19 phoenix kernel: [<ffffffff8118ef32>] ?
alloc_fd+0x92/0x160
Dec 14 09:09:19 phoenix kernel: [<ffffffff8116f6d9>]
do_sys_open+0x69/0x140
Dec 14 09:09:19 phoenix kernel: [<ffffffff8116f7f0>] sys_open+0x20/0x30
Dec 14 09:09:19 phoenix kernel: [<ffffffff8100b172>]
system_call_fastpath+0x16/0x1b
Dec 14 09:09:19 phoenix kernel: INFO: task mtx:19095 blocked for more
than 120 seconds.
Dec 14 09:09:19 phoenix kernel: "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dec 14 09:09:19 phoenix kernel: mtx D 0000000000000004 0
19095 1 0x00000084
Dec 14 09:09:19 phoenix kernel: ffff88000f775bf8 0000000000000086
0000000000000000 00000000000280da
Dec 14 09:09:19 phoenix kernel: ffff88000f775c78 ffffffff8111fb21
ffff880000028d80 0000000103330135
Dec 14 09:09:19 phoenix kernel: ffff88024126bb38 ffff88000f775fd8
000000000000f598 ffff88024126bb38
Dec 14 09:09:19 phoenix kernel: Call Trace:
Dec 14 09:09:19 phoenix kernel: [<ffffffff8111fb21>] ?
__alloc_pages_nodemask+0x111/0x8b0
Dec 14 09:09:19 phoenix kernel: [<ffffffff813545b5>]
scsi_block_when_processing_errors+0xd5/0x100
Dec 14 09:09:19 phoenix kernel: [<ffffffff8108e100>] ?
autoremove_wake_function+0x0/0x40
Dec 14 09:09:19 phoenix kernel: [<ffffffffa03dbfbe>] sg_open+0x23e/0x630
[sg]
Dec 14 09:09:19 phoenix kernel: [<ffffffff81264bfa>] ?
kobject_get+0x1a/0x30
Dec 14 09:09:19 phoenix kernel: [<ffffffff81175c31>] ?
cdev_get+0x31/0xe0
Dec 14 09:09:19 phoenix kernel: [<ffffffff811766d5>]
chrdev_open+0x125/0x230
Dec 14 09:09:19 phoenix kernel: [<ffffffff811765b0>] ?
chrdev_open+0x0/0x230
Dec 14 09:09:19 phoenix kernel: [<ffffffff8116f92a>]
__dentry_open+0x10a/0x360
Dec 14 09:09:19 phoenix kernel: [<ffffffff8120605f>] ?
security_inode_permission+0x1f/0x30
Dec 14 09:09:19 phoenix kernel: [<ffffffff8116fc94>]
nameidata_to_filp+0x54/0x70
Dec 14 09:09:19 phoenix kernel: [<ffffffff811828f0>]
do_filp_open+0x700/0xd90
Dec 14 09:09:19 phoenix kernel: [<ffffffff81041594>] ?
__do_page_fault+0x1e4/0x480
Dec 14 09:09:19 phoenix kernel: [<ffffffff81190f40>] ?
mntput_no_expire+0x30/0x110
Dec 14 09:09:19 phoenix kernel: [<ffffffff81173f31>] ?
__fput+0x1a1/0x210
Dec 14 09:09:19 phoenix kernel: [<ffffffff8118ef32>] ?
alloc_fd+0x92/0x160
Dec 14 09:09:19 phoenix kernel: [<ffffffff8116f6d9>]
do_sys_open+0x69/0x140
Dec 14 09:09:19 phoenix kernel: [<ffffffff8116f7f0>] sys_open+0x20/0x30
Dec 14 09:09:19 phoenix kernel: [<ffffffff8100b172>]
system_call_fastpath+0x16/0x1b
Dec 14 09:11:19 phoenix kernel: INFO: task tar:14772 blocked for more
than 120 seconds.
Dec 14 09:11:19 phoenix kernel: "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dec 14 09:11:19 phoenix kernel: tar D 0000000000000002 0
14772 14657 0x00000080
Dec 14 09:11:19 phoenix kernel: ffff8801059d9c28 0000000000000082
0000000000000000 0000000000000000
Dec 14 09:11:19 phoenix kernel: ffff8801209350c0 000000018124eed1
ffff88023bfdd200 ffff880246304090
Dec 14 09:11:19 phoenix kernel: ffff880244ad50b8 ffff8801059d9fd8
000000000000f598 ffff880244ad50b8
Dec 14 09:11:19 phoenix kernel: Call Trace:
Dec 14 09:11:19 phoenix kernel: [<ffffffff814db5a5>]
schedule_timeout+0x215/0x2e0
Dec 14 09:11:19 phoenix kernel: [<ffffffff814db223>]
wait_for_common+0x123/0x180
Dec 14 09:11:19 phoenix kernel: [<ffffffff8105dc20>] ?
default_wake_function+0x0/0x20
Dec 14 09:11:19 phoenix kernel: [<ffffffff81247812>] ?
__generic_unplug_device+0x32/0x40
Dec 14 09:11:19 phoenix kernel: [<ffffffff814db33d>]
wait_for_completion+0x1d/0x20
Dec 14 09:11:19 phoenix kernel: [<ffffffffa03e74c3>]
st_do_scsi.clone.0+0x213/0x380 [st]
Dec 14 09:11:19 phoenix kernel: [<ffffffffa03ebf12>]
st_write+0x5a2/0xc70 [st]
Dec 14 09:11:19 phoenix kernel: [<ffffffff8108e100>] ?
autoremove_wake_function+0x0/0x40
Dec 14 09:11:19 phoenix kernel: [<ffffffff811725a8>]
vfs_write+0xb8/0x1a0
Dec 14 09:11:19 phoenix kernel: [<ffffffff81172fe1>] sys_write+0x51/0x90
Dec 14 09:11:19 phoenix kernel: [<ffffffff8100b172>]
system_call_fastpath+0x16/0x1b
Dec 14 09:13:58 phoenix init: tty (/dev/tty2) main process (2165) killed
by TERM signal
Any advice would be appreciated!
John
|
