search

renzhengeek / issues

0 stars 0 forks source link

read path #23

Closed renzhengeek closed 8 years ago

renzhengeek commented 8 years ago 
# Cat / proc / 27915 / stack  
[<ffffffffa0632340>] __ocfs2_cluster_lock + 0x310 /
 0x910 [ocfs2]  
[<ffffffffa0639cd8>] ocfs2_inode_lock_full_nested +
 0x178 / 0x510 [ocfs2]  
[<ffffffffa063a2f2>] ocfs2_inode_lock_with_page + 0
x72 / 0x90 [ocfs2]  
[<ffffffffa062070f>] ocfs2_readpage + 0x8f / 0x210 
[ocfs2]  
[<ffffffff810fbfce>] do_generic_file_read + 0x13e /
 0x490  
[<ffffffff810fc97c>] generic_file_aio_read + 0xfc /
 0x260  
[<ffffffffa064067b>] ocfs2_file_aio_read + 0x14b / 
0x390 [ocfs2]  
[<ffffffff8115d4d8>] do_sync_read + 0xc8 / 0x110  
[<ffffffff8115dc87>] vfs_read + 0xC7 / 0x130  
[<ffffffff8115ddf3>] SYS_read + 0x53 / 0xA0  
[<ffffffff8146e030>] sysenter_dispatch + 0x7 / 0x2E
[<00000000ffffe430>] 0xffffe430  
[<FFFFFFFFFFFFFFFF>] 0xFFFFFFFFFFFFFFFF
renzhengeek commented 8 years ago

DIO read

n2:~ # cat /proc/30793/stack 
[<ffffffffa0411350>] __ocfs2_cluster_lock+0x310/0x910 [ocfs2]
[<ffffffffa041554b>] ocfs2_rw_lock+0x7b/0x180 [ocfs2]
[<ffffffffa041f674>] ocfs2_file_aio_read+0xe4/0x390 [ocfs2]
[<ffffffff811584b8>] do_sync_read+0xc8/0x110
[<ffffffff81158c67>] vfs_read+0xc7/0x130
[<ffffffff81158dd3>] sys_read+0x53/0xa0
[<ffffffff81464592>] system_call_fastpath+0x16/0x1b
[<00007f597787f2a0>] 0x7f597787f2a0
[<ffffffffffffffff>] 0xffffffffffffffff
n2:~ # cat /proc/30793/stack 
[<ffffffffa0411350>] __ocfs2_cluster_lock+0x310/0x910 [ocfs2]
[<ffffffffa041554b>] ocfs2_rw_lock+0x7b/0x180 [ocfs2]
[<ffffffffa041f674>] ocfs2_file_aio_read+0xe4/0x390 [ocfs2]
[<ffffffff811584b8>] do_sync_read+0xc8/0x110
[<ffffffff81158c67>] vfs_read+0xc7/0x130
[<ffffffff81158dd3>] sys_read+0x53/0xa0
[<ffffffff81464592>] system_call_fastpath+0x16/0x1b
[<00007f597787f2a0>] 0x7f597787f2a0
[<ffffffffffffffff>] 0xffffffffffffffff
n2:~ # cat /proc/30793/stack 
[<ffffffffa0411350>] __ocfs2_cluster_lock+0x310/0x910 [ocfs2]
[<ffffffffa041554b>] ocfs2_rw_lock+0x7b/0x180 [ocfs2]
[<ffffffffa041f674>] ocfs2_file_aio_read+0xe4/0x390 [ocfs2]
[<ffffffff811584b8>] do_sync_read+0xc8/0x110
[<ffffffff81158c67>] vfs_read+0xc7/0x130
[<ffffffff81158dd3>] sys_read+0x53/0xa0
[<ffffffff81464592>] system_call_fastpath+0x16/0x1b
[<00007f597787f2a0>] 0x7f597787f2a0
[<ffffffffffffffff>] 0xffffffffffffffff
n2:~ # cat /proc/30793/stack 
[<ffffffffa0411350>] __ocfs2_cluster_lock+0x310/0x910 [ocfs2]
[<ffffffffa041554b>] ocfs2_rw_lock+0x7b/0x180 [ocfs2]
[<ffffffffa041f674>] ocfs2_file_aio_read+0xe4/0x390 [ocfs2]
[<ffffffff811584b8>] do_sync_read+0xc8/0x110
[<ffffffff81158c67>] vfs_read+0xc7/0x130
[<ffffffff81158dd3>] sys_read+0x53/0xa0
[<ffffffff81464592>] system_call_fastpath+0x16/0x1b
[<00007f597787f2a0>] 0x7f597787f2a0
[<ffffffffffffffff>] 0xffffffffffffffff
n2:~ # cat /proc/30793/stack 
[<ffffffff81186579>] sleep_on_buffer+0x9/0x10
[<ffffffffa0403f28>] ocfs2_read_blocks+0x3b8/0x690 [ocfs2]
[<ffffffffa04230f7>] ocfs2_read_inode_block_full+0x37/0x60 [ocfs2]
[<ffffffffa041b225>] ocfs2_get_clusters+0x135/0x390 [ocfs2]
[<ffffffffa041b4dc>] ocfs2_extent_map_get_blocks+0x5c/0x1a0 [ocfs2]
[<ffffffffa03fe579>] ocfs2_direct_IO_get_blocks+0x59/0x190 [ocfs2]
[<ffffffff8118e26d>] do_direct_IO+0x18d/0x420
[<ffffffff8118e6a9>] direct_io_worker+0x1a9/0x340
[<ffffffffa03fe40a>] ocfs2_direct_IO+0x7a/0x80 [ocfs2]
[<ffffffff810f9e77>] generic_file_aio_read+0x237/0x260
[<ffffffffa041f6db>] ocfs2_file_aio_read+0x14b/0x390 [ocfs2]
[<ffffffff811584b8>] do_sync_read+0xc8/0x110
[<ffffffff81158c67>] vfs_read+0xc7/0x130
[<ffffffff81158dd3>] sys_read+0x53/0xa0
[<ffffffff81464592>] system_call_fastpath+0x16/0x1b
[<00007f597787f2a0>] 0x7f597787f2a0
[<ffffffffffffffff>] 0xffffffffffffffff
n2:~ # cat /proc/30793/stack 
[<ffffffffa0411350>] __ocfs2_cluster_lock+0x310/0x910 [ocfs2]
[<ffffffffa041554b>] ocfs2_rw_lock+0x7b/0x180 [ocfs2]
[<ffffffffa041f674>] ocfs2_file_aio_read+0xe4/0x390 [ocfs2]
[<ffffffff811584b8>] do_sync_read+0xc8/0x110
[<ffffffff81158c67>] vfs_read+0xc7/0x130
[<ffffffff81158dd3>] sys_read+0x53/0xa0
[<ffffffff81464592>] system_call_fastpath+0x16/0x1b
[<00007f597787f2a0>] 0x7f597787f2a0
[<ffffffffffffffff>] 0xffffffffffffffff
n2:~ # cat /proc/30793/stack 
[<ffffffff8118dabf>] dio_await_completion+0x5f/0xe0
[<ffffffff8118e77f>] direct_io_worker+0x27f/0x340
[<ffffffffa03fe40a>] ocfs2_direct_IO+0x7a/0x80 [ocfs2]
[<ffffffff810f9e77>] generic_file_aio_read+0x237/0x260
[<ffffffffa041f6db>] ocfs2_file_aio_read+0x14b/0x390 [ocfs2]
[<ffffffff811584b8>] do_sync_read+0xc8/0x110
[<ffffffff81158c67>] vfs_read+0xc7/0x130
[<ffffffff81158dd3>] sys_read+0x53/0xa0
[<ffffffff81464592>] system_call_fastpath+0x16/0x1b
[<00007f597787f2a0>] 0x7f597787f2a0
[<ffffffffffffffff>] 0xffffffffffffffff

DIO write

n1:/usr/src/linux/fs/ocfs2 # cat /proc/1588/stack 
[<ffffffffa040a350>] __ocfs2_cluster_lock+0x310/0x910 [ocfs2]
[<ffffffffa040e54b>] ocfs2_rw_lock+0x7b/0x180 [ocfs2]
[<ffffffffa0417e9d>] ocfs2_file_aio_write+0x26d/0x960 [ocfs2]
[<ffffffff811583a8>] do_sync_write+0xc8/0x110
[<ffffffff811589de>] vfs_write+0xce/0x140
[<ffffffff81158b53>] sys_write+0x53/0xa0
[<ffffffff81464592>] system_call_fastpath+0x16/0x1b
[<00007f74e48cf300>] 0x7f74e48cf300
[<ffffffffffffffff>] 0xffffffffffffffff
n1:/usr/src/linux/fs/ocfs2 # cat /proc/1588/stack 
[<ffffffffa040a350>] __ocfs2_cluster_lock+0x310/0x910 [ocfs2]
[<ffffffffa040e54b>] ocfs2_rw_lock+0x7b/0x180 [ocfs2]
[<ffffffffa0417e9d>] ocfs2_file_aio_write+0x26d/0x960 [ocfs2]
[<ffffffff811583a8>] do_sync_write+0xc8/0x110
[<ffffffff811589de>] vfs_write+0xce/0x140
[<ffffffff81158b53>] sys_write+0x53/0xa0
[<ffffffff81464592>] system_call_fastpath+0x16/0x1b
[<00007f74e48cf300>] 0x7f74e48cf300
[<ffffffffffffffff>] 0xffffffffffffffff
n1:/usr/src/linux/fs/ocfs2 # cat /proc/1588/stack 
[<ffffffff8118dabf>] dio_await_completion+0x5f/0xe0
[<ffffffff8118e77f>] direct_io_worker+0x27f/0x340
[<ffffffffa03f740a>] ocfs2_direct_IO+0x7a/0x80 [ocfs2]
[<ffffffff810f9b58>] generic_file_direct_write+0xc8/0x1b0
[<ffffffffa041840b>] ocfs2_file_aio_write+0x7db/0x960 [ocfs2]
[<ffffffff811583a8>] do_sync_write+0xc8/0x110
[<ffffffff811589de>] vfs_write+0xce/0x140
[<ffffffff81158b53>] sys_write+0x53/0xa0
[<ffffffff81464592>] system_call_fastpath+0x16/0x1b
[<00007f74e48cf300>] 0x7f74e48cf300
[<ffffffffffffffff>] 0xffffffffffffffff
renzhengeek commented 8 years ago

read

n2:~ # cat /proc/31167/stack ]
[<ffffffffa0411350>] __ocfs2_cluster_lock+0x310/0x910 [ocfs2]
[<ffffffffa0418ce8>] ocfs2_inode_lock_full_nested+0x178/0x510 [ocfs2]
[<ffffffffa0419302>] ocfs2_inode_lock_with_page+0x72/0x90 [ocfs2]
[<ffffffffa03ff70f>] ocfs2_readpage+0x8f/0x210 [ocfs2]
[<ffffffff810f938e>] do_generic_file_read+0x13e/0x490
[<ffffffff810f9d3c>] generic_file_aio_read+0xfc/0x260
[<ffffffffa041f6db>] ocfs2_file_aio_read+0x14b/0x390 [ocfs2]
[<ffffffff811584b8>] do_sync_read+0xc8/0x110
[<ffffffff81158c67>] vfs_read+0xc7/0x130
[<ffffffff81158dd3>] sys_read+0x53/0xa0
[<ffffffff81464592>] system_call_fastpath+0x16/0x1b
[<00007f5313d602a0>] 0x7f5313d602a0
[<ffffffffffffffff>] 0xffffffffffffffff
cat: ]: No such file or directory
n2:~ # cat /proc/31167/stack ]
[<ffffffffa0411350>] __ocfs2_cluster_lock+0x310/0x910 [ocfs2]
[<ffffffffa0418ce8>] ocfs2_inode_lock_full_nested+0x178/0x510 [ocfs2]
[<ffffffffa0419302>] ocfs2_inode_lock_with_page+0x72/0x90 [ocfs2]
[<ffffffffa03ff70f>] ocfs2_readpage+0x8f/0x210 [ocfs2]
[<ffffffff810f938e>] do_generic_file_read+0x13e/0x490
[<ffffffff810f9d3c>] generic_file_aio_read+0xfc/0x260
[<ffffffffa041f6db>] ocfs2_file_aio_read+0x14b/0x390 [ocfs2]
[<ffffffff811584b8>] do_sync_read+0xc8/0x110
[<ffffffff81158c67>] vfs_read+0xc7/0x130
[<ffffffff81158dd3>] sys_read+0x53/0xa0
[<ffffffff81464592>] system_call_fastpath+0x16/0x1b
[<00007f5313d602a0>] 0x7f5313d602a0
[<ffffffffffffffff>] 0xffffffffffffffff
cat: ]: No such file or directory
n2:~ # cat /proc/31167/stack ]
[<ffffffffa0411350>] __ocfs2_cluster_lock+0x310/0x910 [ocfs2]
[<ffffffffa0418ce8>] ocfs2_inode_lock_full_nested+0x178/0x510 [ocfs2]
[<ffffffffa0419302>] ocfs2_inode_lock_with_page+0x72/0x90 [ocfs2]
[<ffffffffa03ff70f>] ocfs2_readpage+0x8f/0x210 [ocfs2]
[<ffffffff810f938e>] do_generic_file_read+0x13e/0x490
[<ffffffff810f9d3c>] generic_file_aio_read+0xfc/0x260
[<ffffffffa041f6db>] ocfs2_file_aio_read+0x14b/0x390 [ocfs2]
[<ffffffff811584b8>] do_sync_read+0xc8/0x110
[<ffffffff81158c67>] vfs_read+0xc7/0x130
[<ffffffff81158dd3>] sys_read+0x53/0xa0
[<ffffffff81464592>] system_call_fastpath+0x16/0x1b
[<00007f5313d602a0>] 0x7f5313d602a0
[<ffffffffffffffff>] 0xffffffffffffffff

write

n1:/usr/src/linux/fs/ocfs2 # cat /proc/2062/stack 
[<ffffffff81186579>] sleep_on_buffer+0x9/0x10
[<ffffffffa03f905b>] ocfs2_map_page_blocks+0x22b/0x370 [ocfs2]
[<ffffffffa03f9351>] ocfs2_prepare_page_for_write+0x1b1/0x320 [ocfs2]
[<ffffffffa03fa41a>] ocfs2_write_cluster+0xfa/0x540 [ocfs2]
[<ffffffffa03fb8ac>] ocfs2_write_begin_nolock+0x104c/0x11d0 [ocfs2]
[<ffffffffa03fbb47>] ocfs2_write_begin+0x117/0x240 [ocfs2]
[<ffffffff810f73f2>] generic_perform_write+0xc2/0x1c0
[<ffffffff810f7551>] generic_file_buffered_write+0x61/0xa0
[<ffffffffa041855f>] ocfs2_file_aio_write+0x92f/0x960 [ocfs2]
[<ffffffff811583a8>] do_sync_write+0xc8/0x110
[<ffffffff811589de>] vfs_write+0xce/0x140
[<ffffffff81158b53>] sys_write+0x53/0xa0
[<ffffffff81464592>] system_call_fastpath+0x16/0x1b
[<00007f2b8639e300>] 0x7f2b8639e300
[<ffffffffffffffff>] 0xffffffffffffffff
n1:/usr/src/linux/fs/ocfs2 # cat /proc/2062/stack 
[<ffffffffa040a350>] __ocfs2_cluster_lock+0x310/0x910 [ocfs2]
[<ffffffffa0411ce8>] ocfs2_inode_lock_full_nested+0x178/0x510 [ocfs2]
[<ffffffffa03fba8b>] ocfs2_write_begin+0x5b/0x240 [ocfs2]
[<ffffffff810f73f2>] generic_perform_write+0xc2/0x1c0
[<ffffffff810f7551>] generic_file_buffered_write+0x61/0xa0
[<ffffffffa041855f>] ocfs2_file_aio_write+0x92f/0x960 [ocfs2]
[<ffffffff811583a8>] do_sync_write+0xc8/0x110
[<ffffffff811589de>] vfs_write+0xce/0x140
[<ffffffff81158b53>] sys_write+0x53/0xa0
[<ffffffff81464592>] system_call_fastpath+0x16/0x1b
[<00007f2b8639e300>] 0x7f2b8639e300
[<ffffffffffffffff>] 0xffffffffffffffff
n1:/usr/src/linux/fs/ocfs2 # cat /proc/2062/stack 
[<ffffffffa040a350>] __ocfs2_cluster_lock+0x310/0x910 [ocfs2]
[<ffffffffa0411ce8>] ocfs2_inode_lock_full_nested+0x178/0x510 [ocfs2]
[<ffffffffa03fba8b>] ocfs2_write_begin+0x5b/0x240 [ocfs2]
[<ffffffff810f73f2>] generic_perform_write+0xc2/0x1c0
[<ffffffff810f7551>] generic_file_buffered_write+0x61/0xa0
[<ffffffffa041855f>] ocfs2_file_aio_write+0x92f/0x960 [ocfs2]
[<ffffffff811583a8>] do_sync_write+0xc8/0x110
[<ffffffff811589de>] vfs_write+0xce/0x140
[<ffffffff81158b53>] sys_write+0x53/0xa0
[<ffffffff81464592>] system_call_fastpath+0x16/0x1b
[<00007f2b8639e300>] 0x7f2b8639e300
[<ffffffffffffffff>] 0xffffffffffffffff
n1:/usr/src/linux/fs/ocfs2 # cat /proc/2062/stack 
[<ffffffffa040a350>] __ocfs2_cluster_lock+0x310/0x910 [ocfs2]
[<ffffffffa0411ce8>] ocfs2_inode_lock_full_nested+0x178/0x510 [ocfs2]
[<ffffffffa03fba8b>] ocfs2_write_begin+0x5b/0x240 [ocfs2]
[<ffffffff810f73f2>] generic_perform_write+0xc2/0x1c0
[<ffffffff810f7551>] generic_file_buffered_write+0x61/0xa0
[<ffffffffa041855f>] ocfs2_file_aio_write+0x92f/0x960 [ocfs2]
[<ffffffff811583a8>] do_sync_write+0xc8/0x110
[<ffffffff811589de>] vfs_write+0xce/0x140
[<ffffffff81158b53>] sys_write+0x53/0xa0
[<ffffffff81464592>] system_call_fastpath+0x16/0x1b
[<00007f2b8639e300>] 0x7f2b8639e300
[<ffffffffffffffff>] 0xffffffffffffffff
renzhengeek commented 8 years ago

difference read:

[<ffffffffa0418ce8>] ocfs2_inode_lock_full_nested+0x178/0x510 [ocfs2]
[<ffffffffa0419302>] ocfs2_inode_lock_with_page+0x72/0x90 [ocfs2]
[<ffffffffa03ff70f>] ocfs2_readpage+0x8f/0x210 [ocfs2]
[<ffffffff810f938e>] do_generic_file_read+0x13e/0x490
[<ffffffff810f9d3c>] generic_file_aio_read+0xfc/0x260

vs 

[<ffffffffa0411350>] __ocfs2_cluster_lock+0x310/0x910 [ocfs2]
[<ffffffffa041554b>] ocfs2_rw_lock+0x7b/0x180 [ocfs2]
renzhengeek commented 8 years ago

write:

Nov 11 14:49:28 n1 kernel: [  417.655811] ocfs2_inode_lock_full_nested-->
Nov 11 14:49:28 n1 kernel: [  417.655812] __ocfs2_cluster_lock-->
Nov 11 14:49:28 n1 kernel: [  417.655813] blocked on behalf of another node
Nov 11 14:49:28 n1 kernel: [  417.665762] wait=1; goto unlock
Nov 11 14:49:28 n1 kernel: [  417.666297] OCFS2_LOCK_UPCONVERT_FINISHING: level(5):->l_level(5)
Nov 11 14:49:28 n1 kernel: [  417.666300] __ocfs2_cluster_lock<--
Nov 11 14:49:28 n1 kernel: [  417.666304] ocfs2_inode_lock_full_nested<-- 10 ms
Nov 11 14:49:28 n1 kernel: [  417.666331] __ocfs2_cluster_lock-->
Nov 11 14:49:28 n1 kernel: [  417.666333] __ocfs2_cluster_lock<--
Nov 11 14:49:28 n1 kernel: [  417.666334] ocfs2_inode_lock_full_nested-->
Nov 11 14:49:30 n1 kernel: [  417.666335] __ocfs2_cluster_lock-->
Nov 11 14:49:30 n1 kernel: [  417.666336] __ocfs2_cluster_lock<--
Nov 11 14:49:30 n1 kernel: [  417.666337] ocfs2_inode_lock_full_nested<-- 0 ms
Nov 11 14:49:30 n1 kernel: [  417.666339] ocfs2_inode_lock_full_nested-->
Nov 11 14:49:30 n1 kernel: [  417.666340] __ocfs2_cluster_lock-->
Nov 11 14:49:30 n1 kernel: [  417.666341] blocked on behalf of another node
Nov 11 14:49:30 n1 kernel: [  417.678835] wait=1; goto unlock
Nov 11 14:49:30 n1 kernel: [  417.679406] OCFS2_LOCK_UPCONVERT_FINISHING: level(5):->l_level(5)
Nov 11 14:49:30 n1 kernel: [  417.679409] __ocfs2_cluster_lock<--
Nov 11 14:49:30 n1 kernel: [  417.679413] ocfs2_inode_lock_full_nested<-- 13 ms
Nov 11 14:49:30 n1 kernel: [  417.679445] __ocfs2_cluster_lock-->
Nov 11 14:49:30 n1 kernel: [  417.679448] __ocfs2_cluster_lock<--
Nov 11 14:49:30 n1 kernel: [  417.679450] ocfs2_inode_lock_full_nested-->
Nov 11 14:49:30 n1 kernel: [  417.679452] __ocfs2_cluster_lock-->
Nov 11 14:49:30 n1 kernel: [  417.679453] __ocfs2_cluster_lock<--
Nov 11 14:49:30 n1 kernel: [  417.679456] ocfs2_inode_lock_full_nested<-- 0 ms
Nov 11 14:49:30 n1 kernel: [  417.679458] ocfs2_inode_lock_full_nested-->
Nov 11 14:49:30 n1 kernel: [  417.679460] __ocfs2_cluster_lock-->
Nov 11 14:49:30 n1 kernel: [  417.679462] blocked on behalf of another node
Nov 11 14:49:30 n1 kernel: [  417.689918] wait=1; goto unlock
Nov 11 14:49:31 n1 kernel: [  417.690423] OCFS2_LOCK_UPCONVERT_FINISHING: level(5):->l_level(5)
Nov 11 14:49:31 n1 kernel: [  417.690425] __ocfs2_cluster_lock<--
Nov 11 14:49:31 n1 kernel: [  417.690428] ocfs2_inode_lock_full_nested<-- 10 ms
renzhengeek commented 8 years ago

read

Nov 11 14:24:05 n2 kernel: [  205.893525] ocfs2_inode_lock_full_nested-->
Nov 11 14:24:05 n2 kernel: [  205.893526] __ocfs2_cluster_lock-->
Nov 11 14:24:05 n2 kernel: [  205.893527] blocked on behalf of another node
Nov 11 14:24:05 n2 kernel: [  205.893549] wait=1; goto unlock
Nov 11 14:24:05 n2 kernel: [  205.906053] OCFS2_LOCK_UPCONVERT_FINISHING: level(3):->l_level(3)
Nov 11 14:24:05 n2 kernel: [  205.906056] __ocfs2_cluster_lock<--
Nov 11 14:24:05 n2 kernel: [  205.906058] ocfs2_inode_lock_full_nested<-- 12 ms
Nov 11 14:24:05 n2 kernel: [  205.906060] ocfs2_inode_lock_with_page<-- 12 ms
Nov 11 14:24:05 n2 kernel: [  205.906061] ocfs2_readpage<--
Nov 11 14:24:06 n2 kernel: [  205.906065] ocfs2_inode_lock_full_nested-->
Nov 11 14:24:06 n2 kernel: [  205.906066] __ocfs2_cluster_lock-->
Nov 11 14:24:06 n2 kernel: [  205.906067] blocked on behalf of another node
Nov 11 14:24:06 n2 kernel: [  205.906068] __ocfs2_cluster_lock<--
Nov 11 14:24:06 n2 kernel: [  205.906069] ocfs2_inode_lock_full_nested<-- 0 ms
Nov 11 14:24:06 n2 kernel: [  205.906072] ocfs2_readpage-->
Nov 11 14:24:06 n2 kernel: [  205.906073] ocfs2_readpage: 1447223041s 906ms
Nov 11 14:24:06 n2 kernel: [  205.906075] ocfs2_inode_lock_with_page-->
Nov 11 14:24:06 n2 kernel: [  205.906076] ocfs2_inode_lock_full_nested-->
Nov 11 14:24:06 n2 kernel: [  205.906077] __ocfs2_cluster_lock-->
Nov 11 14:24:06 n2 kernel: [  205.906078] blocked on behalf of another node
Nov 11 14:24:06 n2 kernel: [  205.906079] __ocfs2_cluster_lock<--
Nov 11 14:24:06 n2 kernel: [  205.906080] ocfs2_inode_lock_full_nested<-- 0 ms
Nov 11 14:24:06 n2 kernel: [  205.906081] ocfs2_inode_lock_full_nested-->
Nov 11 14:24:06 n2 kernel: [  205.906082] __ocfs2_cluster_lock-->
Nov 11 14:24:06 n2 kernel: [  205.906083] blocked on behalf of another node
Nov 11 14:24:06 n2 kernel: [  205.906104] wait=1; goto unlock
Nov 11 14:24:06 n2 kernel: [  205.917453] OCFS2_LOCK_UPCONVERT_FINISHING: level(3):->l_level(3)
Nov 11 14:24:06 n2 kernel: [  205.917456] __ocfs2_cluster_lock<--
Nov 11 14:24:06 n2 kernel: [  205.917458] ocfs2_inode_lock_full_nested<-- 11 ms
Nov 11 14:24:06 n2 kernel: [  205.917460] ocfs2_inode_lock_with_page<-- 11 ms
Nov 11 14:24:06 n2 kernel: [  205.917461] ocfs2_readpage<--
Nov 11 14:24:06 n2 kernel: [  205.917465] ocfs2_inode_lock_full_nested-->
Nov 11 14:24:06 n2 kernel: [  205.917466] __ocfs2_cluster_lock-->
Nov 11 14:24:06 n2 kernel: [  205.917467] blocked on behalf of another node
Nov 11 14:24:06 n2 kernel: [  205.917468] __ocfs2_cluster_lock<--
Nov 11 14:24:06 n2 kernel: [  205.917469] ocfs2_inode_lock_full_nested<-- 0 ms
Nov 11 14:24:06 n2 kernel: [  205.917472] ocfs2_readpage-->
Nov 11 14:24:06 n2 kernel: [  205.917473] ocfs2_readpage: 1447223041s 917ms
Nov 11 14:24:08 n2 kernel: [  205.941496] ocfs2_inode_lock_full_nested<-- 0 ms
Nov 11 14:24:08 n2 kernel: [  205.941499] ocfs2_readpage-->
Nov 11 14:24:08 n2 kernel: [  205.941500] ocfs2_readpage: 1447223041s 941ms
Nov 11 14:24:08 n2 kernel: [  205.941501] ocfs2_inode_lock_with_page-->
Nov 11 14:24:08 n2 kernel: [  205.941502] ocfs2_inode_lock_full_nested-->
Nov 11 14:24:08 n2 kernel: [  205.941503] __ocfs2_cluster_lock-->
Nov 11 14:24:08 n2 kernel: [  205.941504] blocked on behalf of another node
Nov 11 14:24:08 n2 kernel: [  205.941505] __ocfs2_cluster_lock<--
Nov 11 14:24:08 n2 kernel: [  205.941507] ocfs2_inode_lock_full_nested<-- 0 ms
Nov 11 14:24:08 n2 kernel: [  205.941508] ocfs2_inode_lock_full_nested-->
Nov 11 14:24:08 n2 kernel: [  205.941509] __ocfs2_cluster_lock-->
Nov 11 14:24:08 n2 kernel: [  205.941510] blocked on behalf of another node
Nov 11 14:24:08 n2 kernel: [  205.941531] wait=1; goto unlock
Nov 11 14:24:08 n2 kernel: [  205.953925] OCFS2_LOCK_UPCONVERT_FINISHING: level(3):->l_level(3)
Nov 11 14:24:08 n2 kernel: [  205.953927] __ocfs2_cluster_lock<--
Nov 11 14:24:08 n2 kernel: [  205.953929] ocfs2_inode_lock_full_nested<-- 12 ms
Nov 11 14:24:08 n2 kernel: [  205.953931] ocfs2_inode_lock_with_page<-- 12 ms
Nov 11 14:24:08 n2 kernel: [  205.953932] ocfs2_readpage<--
Nov 11 14:24:08 n2 kernel: [  205.953936] ocfs2_inode_lock_full_nested-->
Nov 11 14:24:08 n2 kernel: [  205.953937] __ocfs2_cluster_lock-->
Nov 11 14:24:08 n2 kernel: [  205.953938] blocked on behalf of another node
Nov 11 14:24:08 n2 kernel: [  205.953939] __ocfs2_cluster_lock<--
Nov 11 14:24:08 n2 kernel: [  205.953940] ocfs2_inode_lock_full_nested<-- 0 ms
Nov 11 14:24:08 n2 kernel: [  205.953943] ocfs2_readpage-->
Nov 11 14:24:08 n2 kernel: [  205.953944] ocfs2_readpage: 1447223041s 953ms
Nov 11 14:24:08 n2 kernel: [  205.953946] ocfs2_inode_lock_with_page-->
Nov 11 14:24:08 n2 kernel: [  205.953947] ocfs2_inode_lock_full_nested-->
Nov 11 14:24:08 n2 kernel: [  205.953948] __ocfs2_cluster_lock-->
Nov 11 14:24:08 n2 kernel: [  205.953949] blocked on behalf of another node
Nov 11 14:24:08 n2 kernel: [  205.953950] __ocfs2_cluster_lock<--
Nov 11 14:24:08 n2 kernel: [  205.953951] ocfs2_inode_lock_full_nested<-- 0 ms
Nov 11 14:24:08 n2 kernel: [  205.953952] ocfs2_inode_lock_full_nested-->
Nov 11 14:24:08 n2 kernel: [  205.953953] __ocfs2_cluster_lock-->
Nov 11 14:24:08 n2 kernel: [  205.953954] blocked on behalf of another node
Nov 11 14:24:08 n2 kernel: [  205.953975] wait=1; goto unlock
Nov 11 14:24:08 n2 kernel: [  205.965913] OCFS2_LOCK_UPCONVERT_FINISHING: level(3):->l_level(3)
Nov 11 14:24:08 n2 kernel: [  205.965915] __ocfs2_cluster_lock<--
Nov 11 14:24:08 n2 kernel: [  205.965918] ocfs2_inode_lock_full_nested<-- 11 ms
Nov 11 14:24:08 n2 kernel: [  205.965920] ocfs2_inode_lock_with_page<-- 11 ms
Nov 11 14:24:08 n2 kernel: [  205.965921] ocfs2_readpage<--
renzhengeek commented 8 years ago

direct read:

Nov 11 16:25:56 n2 kernel: [ 7440.305170] ocfs2_direct_IO-->
Nov 11 16:25:56 n2 kernel: [ 7440.306112] ocfs2_direct_IO<-- 0 ms
Nov 11 16:25:56 n2 kernel: [ 7440.306115] __ocfs2_cluster_lock-->
Nov 11 16:25:56 n2 kernel: [ 7440.306116] blocked on behalf of another node
Nov 11 16:25:56 n2 kernel: [ 7440.306167] wait=1; goto unlock
Nov 11 16:25:56 n2 kernel: [ 7440.307689] OCFS2_LOCK_UPCONVERT_FINISHING: level(3):->l_level(3)
Nov 11 16:25:56 n2 kernel: [ 7440.307691] __ocfs2_cluster_lock<--
Nov 11 16:25:56 n2 kernel: [ 7440.307693] ocfs2_inode_lock_full_nested-->
Nov 11 16:25:56 n2 kernel: [ 7440.307694] __ocfs2_cluster_lock-->
Nov 11 16:25:56 n2 kernel: [ 7440.307707] wait=1; goto unlock
Nov 11 16:25:56 n2 kernel: [ 7440.308010] OCFS2_LOCK_UPCONVERT_FINISHING: level(3):->l_level(3)
Nov 11 16:25:57 n2 kernel: [ 7440.308011] __ocfs2_cluster_lock<--
Nov 11 16:25:57 n2 kernel: [ 7440.308014] ocfs2_inode_lock_full_nested<-- 0 ms
Nov 11 16:25:57 n2 kernel: [ 7440.308016] ocfs2_direct_IO-->
Nov 11 16:25:57 n2 kernel: [ 7440.309051] ocfs2_direct_IO<-- 1 ms
Nov 11 16:25:57 n2 kernel: [ 7440.309054] __ocfs2_cluster_lock-->
Nov 11 16:25:57 n2 kernel: [ 7440.309055] blocked on behalf of another node
Nov 11 16:25:57 n2 kernel: [ 7440.309106] wait=1; goto unlock
Nov 11 16:25:57 n2 kernel: [ 7440.310636] OCFS2_LOCK_UPCONVERT_FINISHING: level(3):->l_level(3)
Nov 11 16:25:57 n2 kernel: [ 7440.310638] __ocfs2_cluster_lock<--
Nov 11 16:25:57 n2 kernel: [ 7440.310639] ocfs2_inode_lock_full_nested-->
Nov 11 16:25:58 n2 kernel: [ 7440.310640] __ocfs2_cluster_lock-->
Nov 11 16:25:58 n2 kernel: [ 7440.310653] wait=1; goto unlock
Nov 11 16:25:58 n2 kernel: [ 7440.310963] OCFS2_LOCK_UPCONVERT_FINISHING: level(3):->l_level(3)
Nov 11 16:25:58 n2 kernel: [ 7440.310965] __ocfs2_cluster_lock<--
Nov 11 16:25:58 n2 kernel: [ 7440.310968] ocfs2_inode_lock_full_nested<-- 0 ms
Nov 11 16:25:58 n2 kernel: [ 7440.310969] ocfs2_direct_IO-->
Nov 11 16:25:58 n2 kernel: [ 7440.311962] ocfs2_direct_IO<-- 0 ms
Nov 11 16:25:58 n2 kernel: [ 7440.311966] __ocfs2_cluster_lock-->
Nov 11 16:25:58 n2 kernel: [ 7440.311967] blocked on behalf of another node
Nov 11 16:25:58 n2 kernel: [ 7440.312021] wait=1; goto unlock
Nov 11 16:25:59 n2 kernel: [ 7440.313403] OCFS2_LOCK_UPCONVERT_FINISHING: level(3):->l_level(3)
Nov 11 16:25:59 n2 kernel: [ 7440.313404] __ocfs2_cluster_lock<--
Nov 11 16:25:59 n2 kernel: [ 7440.313406] ocfs2_inode_lock_full_nested-->
Nov 11 16:25:59 n2 kernel: [ 7440.313407] __ocfs2_cluster_lock-->
Nov 11 16:25:59 n2 kernel: [ 7440.313419] wait=1; goto unlock
Nov 11 16:25:59 n2 kernel: [ 7440.313710] OCFS2_LOCK_UPCONVERT_FINISHING: level(3):->l_level(3)
Nov 11 16:25:59 n2 kernel: [ 7440.313711] __ocfs2_cluster_lock<--
Nov 11 16:25:59 n2 kernel: [ 7440.313714] ocfs2_inode_lock_full_nested<-- 0 ms
Nov 11 16:25:59 n2 kernel: [ 7440.313715] ocfs2_direct_IO-->
Nov 11 16:25:59 n2 kernel: [ 7440.314680] ocfs2_direct_IO<-- 0 ms
Nov 11 16:26:00 n2 kernel: [ 7440.314683] __ocfs2_cluster_lock-->
Nov 11 16:26:00 n2 kernel: [ 7440.314684] blocked on behalf of another node
Nov 11 16:26:00 n2 kernel: [ 7440.314739] wait=1; goto unlock
Nov 11 16:26:00 n2 kernel: [ 7440.316223] OCFS2_LOCK_UPCONVERT_FINISHING: level(3):->l_level(3)
Nov 11 16:26:00 n2 kernel: [ 7440.316226] __ocfs2_cluster_lock<--
Nov 11 16:26:00 n2 kernel: [ 7440.316228] ocfs2_inode_lock_full_nested-->
Nov 11 16:26:00 n2 kernel: [ 7440.316229] __ocfs2_cluster_lock-->
Nov 11 16:26:00 n2 kernel: [ 7440.316243] wait=1; goto unlock
renzhengeek commented 8 years ago

direct write:

Nov 11 16:25:56 n1 kernel: [ 7559.119025] ocfs2_direct_IO-->
Nov 11 16:25:56 n1 kernel: [ 7559.119631] ocfs2_direct_IO<-- 0 ms
Nov 11 16:25:56 n1 kernel: [ 7559.119638] __ocfs2_cluster_lock-->
Nov 11 16:25:56 n1 kernel: [ 7559.119640] __ocfs2_cluster_lock<--
Nov 11 16:25:56 n1 kernel: [ 7559.119641] ocfs2_inode_lock_full_nested-->
Nov 11 16:25:56 n1 kernel: [ 7559.119642] __ocfs2_cluster_lock-->
Nov 11 16:25:56 n1 kernel: [ 7559.119643] __ocfs2_cluster_lock<--
Nov 11 16:25:56 n1 kernel: [ 7559.119645] ocfs2_inode_lock_full_nested<-- 0 ms
Nov 11 16:25:56 n1 kernel: [ 7559.119646] ocfs2_inode_lock_full_nested-->
Nov 11 16:25:56 n1 kernel: [ 7559.119647] __ocfs2_cluster_lock-->
Nov 11 16:25:56 n1 kernel: [ 7559.119648] __ocfs2_cluster_lock<--
Nov 11 16:25:56 n1 kernel: [ 7559.119649] ocfs2_inode_lock_full_nested<-- 0 ms
Nov 11 16:25:56 n1 kernel: [ 7559.119651] ocfs2_direct_IO-->
Nov 11 16:25:56 n1 kernel: [ 7559.120354] ocfs2_direct_IO<-- 0 ms
Nov 11 16:25:57 n1 kernel: [ 7559.120369] __ocfs2_cluster_lock-->
Nov 11 16:25:57 n1 kernel: [ 7559.120370] __ocfs2_cluster_lock<--
Nov 11 16:25:57 n1 kernel: [ 7559.120371] ocfs2_inode_lock_full_nested-->
Nov 11 16:25:57 n1 kernel: [ 7559.120373] __ocfs2_cluster_lock-->
Nov 11 16:25:57 n1 kernel: [ 7559.120374] __ocfs2_cluster_lock<--
Nov 11 16:25:57 n1 kernel: [ 7559.120375] ocfs2_inode_lock_full_nested<-- 0 ms
Nov 11 16:25:57 n1 kernel: [ 7559.120376] ocfs2_inode_lock_full_nested-->
Nov 11 16:25:57 n1 kernel: [ 7559.120378] __ocfs2_cluster_lock-->
Nov 11 16:25:57 n1 kernel: [ 7559.120379] __ocfs2_cluster_lock<--
Nov 11 16:25:57 n1 kernel: [ 7559.120380] ocfs2_inode_lock_full_nested<-- 0 ms
Nov 11 16:25:58 n1 kernel: [ 7559.120382] ocfs2_direct_IO-->
Nov 11 16:25:58 n1 kernel: [ 7559.120949] ocfs2_direct_IO<-- 0 ms
Nov 11 16:25:58 n1 kernel: [ 7559.120955] __ocfs2_cluster_lock-->
Nov 11 16:25:58 n1 kernel: [ 7559.120957] __ocfs2_cluster_lock<--
Nov 11 16:25:58 n1 kernel: [ 7559.120958] ocfs2_inode_lock_full_nested-->
Nov 11 16:25:58 n1 kernel: [ 7559.120959] __ocfs2_cluster_lock-->
Nov 11 16:25:58 n1 kernel: [ 7559.120960] __ocfs2_cluster_lock<--
Nov 11 16:25:58 n1 kernel: [ 7559.120961] ocfs2_inode_lock_full_nested<-- 0 ms
Nov 11 16:25:58 n1 kernel: [ 7559.120962] ocfs2_inode_lock_full_nested-->
Nov 11 16:25:58 n1 kernel: [ 7559.120963] __ocfs2_cluster_lock-->
Nov 11 16:25:59 n1 kernel: [ 7559.120965] __ocfs2_cluster_lock<--
Nov 11 16:25:59 n1 kernel: [ 7559.120966] ocfs2_inode_lock_full_nested<-- 0 ms
Nov 11 16:25:59 n1 kernel: [ 7559.120967] ocfs2_direct_IO-->
Nov 11 16:25:59 n1 kernel: [ 7559.121579] ocfs2_direct_IO<-- 0 ms
Nov 11 16:25:59 n1 kernel: [ 7559.121586] __ocfs2_cluster_lock-->
Nov 11 16:25:59 n1 kernel: [ 7559.121587] __ocfs2_cluster_lock<--
Nov 11 16:25:59 n1 kernel: [ 7559.121588] ocfs2_inode_lock_full_nested-->
Nov 11 16:25:59 n1 kernel: [ 7559.121590] __ocfs2_cluster_lock-->