search

renzhengeek / issues

0 stars 0 forks source link

ocfs2 4.5.0-rc7-11-default: multiple: multi_reflink_t:17247 blocked for more than 480 seconds #72

Closed renzhengeek closed 8 years ago

renzhengeek commented 8 years ago

node 1:

Mar 10 02:20:57 ocfs2test1 kernel: INFO: task multi_reflink_t:17247 blocked for more than 480 seconds.
Mar 10 02:20:57 ocfs2test1 kernel:       Tainted: G            E   4.5.0-rc7-11-default #1
Mar 10 02:20:57 ocfs2test1 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Mar 10 02:20:57 ocfs2test1 kernel: multi_reflink_t D ffff8800aaf5fca8     0 17247  17243 0x00000000
Mar 10 02:20:57 ocfs2test1 kernel:  ffff8800aaf5fca8 ffffffff81a0f4c0 ffff8800a21f8f40 ffff8800aaf60000
Mar 10 02:20:57 ocfs2test1 kernel:  ffff8800a21f8f40 ffff880107b6ed5c 00000000ffffffff ffff880107b6ed60
Mar 10 02:20:57 ocfs2test1 kernel:  ffff8800aaf5fcc0 ffffffff815d0d15 ffff880107b6ed58 ffff8800aaf5fcd0
Mar 10 02:20:57 ocfs2test1 kernel: Call Trace:
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff815d0d15>] schedule+0x35/0x80
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff815d0f9e>] schedule_preempt_disabled+0xe/0x10
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff815d26af>] __mutex_lock_slowpath+0x8f/0x100
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff815d2737>] mutex_lock+0x17/0x27
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff811f14db>] filename_create+0x6b/0x150
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff811f162d>] user_path_create+0x2d/0x40
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffffa0620190>] ocfs2_reflink_ioctl+0xc0/0x320 [ocfs2]
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffffa0605bb7>] ocfs2_ioctl+0x257/0x670 [ocfs2]
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff811f4b86>] do_vfs_ioctl+0x96/0x580
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff811f0d83>] ? putname+0x53/0x60
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff811f50e9>] SyS_ioctl+0x79/0x90
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff815d466e>] entry_SYSCALL_64_fastpath+0x12/0x71
Mar 10 02:20:57 ocfs2test1 kernel: INFO: task multi_reflink_t:17247 blocked for more than 480 seconds.
Mar 10 02:20:57 ocfs2test1 kernel:       Tainted: G            E   4.5.0-rc7-11-default #1
Mar 10 02:20:57 ocfs2test1 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Mar 10 02:20:57 ocfs2test1 kernel: multi_reflink_t D ffff8800aaf5fca8     0 17247  17243 0x00000000
Mar 10 02:20:57 ocfs2test1 kernel:  ffff8800aaf5fca8 ffffffff81a0f4c0 ffff8800a21f8f40 ffff8800aaf60000
Mar 10 02:20:57 ocfs2test1 kernel:  ffff8800a21f8f40 ffff880107b6ed5c 00000000ffffffff ffff880107b6ed60
Mar 10 02:20:57 ocfs2test1 kernel:  ffff8800aaf5fcc0 ffffffff815d0d15 ffff880107b6ed58 ffff8800aaf5fcd0
Mar 10 02:20:57 ocfs2test1 kernel: Call Trace:
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff815d0d15>] schedule+0x35/0x80
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff815d0f9e>] schedule_preempt_disabled+0xe/0x10
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff815d26af>] __mutex_lock_slowpath+0x8f/0x100
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff815d2737>] mutex_lock+0x17/0x27
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff811f14db>] filename_create+0x6b/0x150
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff811f162d>] user_path_create+0x2d/0x40
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffffa0620190>] ocfs2_reflink_ioctl+0xc0/0x320 [ocfs2]
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffffa0605bb7>] ocfs2_ioctl+0x257/0x670 [ocfs2]
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff811f4b86>] do_vfs_ioctl+0x96/0x580
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff811f0d83>] ? putname+0x53/0x60
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff811f50e9>] SyS_ioctl+0x79/0x90
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff815d466e>] entry_SYSCALL_64_fastpath+0x12/0x71
Mar 10 02:20:57 ocfs2test1 kernel: INFO: task multi_reflink_t:17248 blocked for more than 480 seconds.
Mar 10 02:20:57 ocfs2test1 kernel:       Tainted: G            E   4.5.0-rc7-11-default #1
Mar 10 02:20:57 ocfs2test1 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Mar 10 02:20:57 ocfs2test1 kernel: multi_reflink_t D ffff88010e6b7838     0 17248  17243 0x00000000
Mar 10 02:20:57 ocfs2test1 kernel:  ffff88010e6b7838 ffff880134028300 ffff8801035689c0 ffff88010e6b8000
Mar 10 02:20:57 ocfs2test1 kernel:  7fffffffffffffff ffff88010e6b79d0 ffff8801035689c0 ffff880107b6e938
Mar 10 02:20:57 ocfs2test1 kernel:  ffff88010e6b7850 ffffffff815d0d15 ffff88010e6b79c8 ffff88010e6b78f0
Mar 10 02:20:57 ocfs2test1 kernel: Call Trace:
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff815d0d15>] schedule+0x35/0x80
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff815d3545>] schedule_timeout+0x225/0x2b0
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff810918c2>] ? default_wake_function+0x12/0x20
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff810a8f62>] ? autoremove_wake_function+0x12/0x40
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff810a8805>] ? __wake_up_common+0x55/0x90
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff815d1617>] wait_for_completion+0x97/0xf0
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff810918b0>] ? wake_up_q+0x80/0x80
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffffa05f78d7>] __ocfs2_cluster_lock.isra.37+0x1a7/0x6b0 [ocfs2]
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffffa0601f22>] ? ocfs2_inode_cache_io_unlock+0x12/0x20 [ocfs2]
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffffa05f876d>] ocfs2_inode_lock_full_nested+0x12d/0x840 [ocfs2]
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffffa06412b0>] ? ocfs2_get_system_file_inode+0x60/0x2c0 [ocfs2]
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffffa0656baf>] ocfs2_iop_get_acl+0x4f/0x279 [ocfs2]
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffffa060c643>] ? ocfs2_reserve_local_alloc_bits+0x63/0x290 [ocfs2]
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff8123b751>] get_acl+0x41/0x60
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff8123be0b>] posix_acl_create+0x5b/0x150
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffffa061374a>] ocfs2_mknod+0x8ca/0x1370 [ocfs2]
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffffa0614368>] ocfs2_create+0x58/0x120 [ocfs2]
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff811ee342>] vfs_create+0xc2/0x120
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff811f0825>] path_openat+0xee5/0x12e0
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff811f1c8e>] do_filp_open+0x7e/0xd0
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff8119aa77>] ? vma_merge+0x217/0x300
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff811fe97f>] ? __alloc_fd+0x3f/0x170
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff811e0ec5>] do_sys_open+0x115/0x1f0
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff811e0fbe>] SyS_open+0x1e/0x20
Mar 10 02:20:57 ocfs2test1 kernel:  [<ffffffff815d466e>] entry_SYSCALL_64_fastpath+0x12/0x71
Mar 10 02:44:57 ocfs2test1 kernel: multi_reflink_t D ffff88010e6b7838     0 17248  17243 0x00000000
Mar 10 02:44:57 ocfs2test1 kernel:  ffff88010e6b7838 ffff880134028300 ffff8801035689c0 ffff88010e6b8000
Mar 10 02:44:57 ocfs2test1 kernel:  7fffffffffffffff ffff88010e6b79d0 ffff8801035689c0 ffff880107b6e938
Mar 10 02:44:57 ocfs2test1 kernel:  ffff88010e6b7850 ffffffff815d0d15 ffff88010e6b79c8 ffff88010e6b78f0
Mar 10 02:44:57 ocfs2test1 kernel: Call Trace:
Mar 10 02:44:57 ocfs2test1 kernel:  [<ffffffff815d0d15>] schedule+0x35/0x80
Mar 10 02:44:57 ocfs2test1 kernel:  [<ffffffff815d3545>] schedule_timeout+0x225/0x2b0
Mar 10 02:44:57 ocfs2test1 kernel:  [<ffffffff810918c2>] ? default_wake_function+0x12/0x20
Mar 10 02:44:57 ocfs2test1 kernel:  [<ffffffff810a8f62>] ? autoremove_wake_function+0x12/0x40
Mar 10 02:44:57 ocfs2test1 kernel:  [<ffffffff810a8805>] ? __wake_up_common+0x55/0x90
Mar 10 02:44:57 ocfs2test1 kernel:  [<ffffffff815d1617>] wait_for_completion+0x97/0xf0
Mar 10 02:44:57 ocfs2test1 kernel:  [<ffffffff810918b0>] ? wake_up_q+0x80/0x80
Mar 10 02:44:57 ocfs2test1 kernel:  [<ffffffffa05f78d7>] __ocfs2_cluster_lock.isra.37+0x1a7/0x6b0 [ocfs2]
Mar 10 02:44:57 ocfs2test1 kernel:  [<ffffffffa0601f22>] ? ocfs2_inode_cache_io_unlock+0x12/0x20 [ocfs2]
Mar 10 02:44:57 ocfs2test1 kernel:  [<ffffffffa05f876d>] ocfs2_inode_lock_full_nested+0x12d/0x840 [ocfs2]
Mar 10 02:44:57 ocfs2test1 kernel:  [<ffffffffa06412b0>] ? ocfs2_get_system_file_inode+0x60/0x2c0 [ocfs2]
Mar 10 02:44:57 ocfs2test1 kernel:  [<ffffffffa0656baf>] ocfs2_iop_get_acl+0x4f/0x279 [ocfs2]
Mar 10 02:44:57 ocfs2test1 kernel:  [<ffffffffa060c643>] ? ocfs2_reserve_local_alloc_bits+0x63/0x290 [ocfs2]
Mar 10 02:44:57 ocfs2test1 kernel:  [<ffffffff8123b751>] get_acl+0x41/0x60
Mar 10 02:44:57 ocfs2test1 kernel:  [<ffffffff8123be0b>] posix_acl_create+0x5b/0x150
Mar 10 02:44:57 ocfs2test1 kernel:  [<ffffffffa061374a>] ocfs2_mknod+0x8ca/0x1370 [ocfs2]
Mar 10 02:44:57 ocfs2test1 kernel:  [<ffffffffa0614368>] ocfs2_create+0x58/0x120 [ocfs2]
Mar 10 02:44:57 ocfs2test1 kernel:  [<ffffffff811ee342>] vfs_create+0xc2/0x120
Mar 10 02:44:57 ocfs2test1 kernel:  [<ffffffff811f0825>] path_openat+0xee5/0x12e0
Mar 10 02:44:57 ocfs2test1 kernel:  [<ffffffff811f1c8e>] do_filp_open+0x7e/0xd0
Mar 10 02:44:57 ocfs2test1 kernel:  [<ffffffff8119aa77>] ? vma_merge+0x217/0x300
Mar 10 02:44:57 ocfs2test1 kernel:  [<ffffffff811fe97f>] ? __alloc_fd+0x3f/0x170
Mar 10 02:44:57 ocfs2test1 kernel:  [<ffffffff811e0ec5>] do_sys_open+0x115/0x1f0
Mar 10 02:44:57 ocfs2test1 kernel:  [<ffffffff811e0fbe>] SyS_open+0x1e/0x20
Mar 10 02:44:57 ocfs2test1 kernel:  [<ffffffff815d466e>] entry_SYSCALL_64_fastpath+0x12/0x71
renzhengeek commented 8 years ago

node 2:

Mar 10 02:27:16 ocfs2test2 kernel: INFO: task multi_reflink_t:13472 blocked for more than 480 seconds.
Mar 10 02:27:16 ocfs2test2 kernel:       Tainted: G            E   4.5.0-rc7-11-default #1
Mar 10 02:27:16 ocfs2test2 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Mar 10 02:27:16 ocfs2test2 kernel: multi_reflink_t D ffff88009ad4b8f8     0 13472  13471 0x00000000
Mar 10 02:27:16 ocfs2test2 kernel:  ffff88009ad4b8f8 ffffffff81a0f4c0 ffff88007a54d1c0 ffff88009ad4c000
Mar 10 02:27:16 ocfs2test2 kernel:  7fffffffffffffff ffff88009ad4ba90 ffff88007a54d1c0 ffff88009aaf4178
Mar 10 02:27:16 ocfs2test2 kernel:  ffff88009ad4b910 ffffffff815d0d15 ffff88009ad4ba88 ffff88009ad4b9b0
Mar 10 02:27:16 ocfs2test2 kernel: Call Trace:
Mar 10 02:27:16 ocfs2test2 kernel:  [<ffffffff815d0d15>] schedule+0x35/0x80
Mar 10 02:27:16 ocfs2test2 kernel:  [<ffffffff815d3545>] schedule_timeout+0x225/0x2b0
Mar 10 02:27:16 ocfs2test2 kernel:  [<ffffffffa0443000>] ? 0xffffffffa0443000
Mar 10 02:27:16 ocfs2test2 kernel:  [<ffffffffa04434a0>] ? ocfs2_control_read+0x50/0x50 [ocfs2_stack_user]
Mar 10 02:27:16 ocfs2test2 kernel:  [<ffffffffa0443000>] ? 0xffffffffa0443000
Mar 10 02:27:16 ocfs2test2 kernel:  [<ffffffff815d1617>] wait_for_completion+0x97/0xf0
Mar 10 02:27:16 ocfs2test2 kernel:  [<ffffffff810918b0>] ? wake_up_q+0x80/0x80
Mar 10 02:27:16 ocfs2test2 kernel:  [<ffffffffa04ab8d7>] __ocfs2_cluster_lock.isra.37+0x1a7/0x6b0 [ocfs2]
Mar 10 02:27:16 ocfs2test2 kernel:  [<ffffffff81091489>] ? try_to_wake_up+0x49/0x3d0
Mar 10 02:27:16 ocfs2test2 kernel:  [<ffffffff815d0d15>] ? schedule+0x35/0x80
Mar 10 02:27:16 ocfs2test2 kernel:  [<ffffffff810918c2>] ? default_wake_function+0x12/0x20
Mar 10 02:27:16 ocfs2test2 kernel:  [<ffffffffa04ac76d>] ocfs2_inode_lock_full_nested+0x12d/0x840 [ocfs2]
Mar 10 02:27:16 ocfs2test2 kernel:  [<ffffffff8104ce1e>] ? kvm_clock_get_cycles+0x1e/0x20
Mar 10 02:27:16 ocfs2test2 kernel:  [<ffffffff810d6e4c>] ? ktime_get+0x3c/0xb0
Mar 10 02:27:16 ocfs2test2 kernel:  [<ffffffffa04c709a>] ocfs2_mknod+0x21a/0x1370 [ocfs2]
Mar 10 02:27:16 ocfs2test2 kernel:  [<ffffffffa04c8368>] ocfs2_create+0x58/0x120 [ocfs2]
Mar 10 02:27:16 ocfs2test2 kernel:  [<ffffffff811ee342>] vfs_create+0xc2/0x120
Mar 10 02:27:16 ocfs2test2 kernel:  [<ffffffff811f0825>] path_openat+0xee5/0x12e0
Mar 10 02:27:16 ocfs2test2 kernel:  [<ffffffff811f1c8e>] do_filp_open+0x7e/0xd0
Mar 10 02:27:16 ocfs2test2 kernel:  [<ffffffff8119aa77>] ? vma_merge+0x217/0x300
Mar 10 02:27:16 ocfs2test2 kernel:  [<ffffffff811fe97f>] ? __alloc_fd+0x3f/0x170
Mar 10 02:27:16 ocfs2test2 kernel:  [<ffffffff811e0ec5>] do_sys_open+0x115/0x1f0
Mar 10 02:27:16 ocfs2test2 kernel:  [<ffffffff811e0fbe>] SyS_open+0x1e/0x20
Mar 10 02:27:16 ocfs2test2 kernel:  [<ffffffff815d466e>] entry_SYSCALL_64_fastpath+0x12/0x71
renzhengeek commented 8 years ago

n3:

Mar 10 02:30:01 ocfs2test3 systemd[14095]: pam_unix(systemd-user:session): session closed for user root
Mar 10 02:30:05 ocfs2test3 kernel: INFO: task multi_reflink_t:13027 blocked for more than 480 seconds.
Mar 10 02:30:05 ocfs2test3 kernel:       Tainted: G            E   4.5.0-rc7-11-default #1
Mar 10 02:30:05 ocfs2test3 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Mar 10 02:30:05 ocfs2test3 kernel: multi_reflink_t D ffff88006591fa18     0 13027  13026 0x00000000
Mar 10 02:30:05 ocfs2test3 kernel:  ffff88006591fa18 ffff88008021cc80 ffff8801213acb40 ffff880065920000
Mar 10 02:30:05 ocfs2test3 kernel:  7fffffffffffffff ffff88006591fbb0 ffff8801213acb40 ffff8800806a2178
Mar 10 02:30:05 ocfs2test3 kernel:  ffff88006591fa30 ffffffff815d0d15 ffff88006591fba8 ffff88006591fad0
Mar 10 02:30:05 ocfs2test3 kernel: Call Trace:
Mar 10 02:30:05 ocfs2test3 kernel:  [<ffffffff815d0d15>] schedule+0x35/0x80
Mar 10 02:30:05 ocfs2test3 kernel:  [<ffffffff815d3545>] schedule_timeout+0x225/0x2b0
Mar 10 02:30:05 ocfs2test3 kernel:  [<ffffffffa0590000>] ? 0xffffffffa0590000
Mar 10 02:30:05 ocfs2test3 kernel:  [<ffffffffa05904a0>] ? ocfs2_control_read+0x50/0x50 [ocfs2_stack_user]
Mar 10 02:30:05 ocfs2test3 kernel:  [<ffffffffa0590000>] ? 0xffffffffa0590000
Mar 10 02:30:05 ocfs2test3 kernel:  [<ffffffff815d1617>] wait_for_completion+0x97/0xf0
Mar 10 02:30:05 ocfs2test3 kernel:  [<ffffffff810918b0>] ? wake_up_q+0x80/0x80
Mar 10 02:30:05 ocfs2test3 kernel:  [<ffffffffa06018d7>] __ocfs2_cluster_lock.isra.37+0x1a7/0x6b0 [ocfs2]
Mar 10 02:30:05 ocfs2test3 kernel:  [<ffffffffa060276d>] ocfs2_inode_lock_full_nested+0x12d/0x840 [ocfs2]
Mar 10 02:30:05 ocfs2test3 kernel:  [<ffffffffa05ffc59>] ? ocfs2_wake_downconvert_thread+0x49/0x50 [ocfs2]
Mar 10 02:30:05 ocfs2test3 kernel:  [<ffffffffa0605c81>] ocfs2_permission+0x31/0xd0 [ocfs2]
Mar 10 02:30:05 ocfs2test3 kernel:  [<ffffffff811ecd3e>] __inode_permission+0x5e/0xb0
Mar 10 02:30:05 ocfs2test3 kernel:  [<ffffffff811ecda8>] inode_permission+0x18/0x50
Mar 10 02:30:05 ocfs2test3 kernel:  [<ffffffff811ee2dc>] vfs_create+0x5c/0x120
Mar 10 02:30:05 ocfs2test3 kernel:  [<ffffffff811f0825>] path_openat+0xee5/0x12e0
Mar 10 02:30:05 ocfs2test3 kernel:  [<ffffffff811f1c8e>] do_filp_open+0x7e/0xd0
Mar 10 02:30:05 ocfs2test3 kernel:  [<ffffffff8119aa77>] ? vma_merge+0x217/0x300
Mar 10 02:30:05 ocfs2test3 kernel:  [<ffffffff811fe97f>] ? __alloc_fd+0x3f/0x170
Mar 10 02:30:05 ocfs2test3 kernel:  [<ffffffff811e0ec5>] do_sys_open+0x115/0x1f0
Mar 10 02:30:05 ocfs2test3 kernel:  [<ffffffff811e0fbe>] SyS_open+0x1e/0x20
Mar 10 02:30:05 ocfs2test3 kernel:  [<ffffffff815d466e>] entry_SYSCALL_64_fastpath+0x12/0x71
Mar 10 02:38:05 ocfs2test3 kernel: INFO: task multi_reflink_t:13027 blocked for more than 480 seconds.
Mar 10 02:38:05 ocfs2test3 kernel:       Tainted: G            E   4.5.0-rc7-11-default #1
Mar 10 02:38:05 ocfs2test3 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Mar 10 02:38:05 ocfs2test3 kernel: multi_reflink_t D ffff88006591fa18     0 13027  13026 0x00000000
Mar 10 02:38:05 ocfs2test3 kernel:  ffff88006591fa18 ffff88008021cc80 ffff8801213acb40 ffff880065920000
Mar 10 02:38:05 ocfs2test3 kernel:  7fffffffffffffff ffff88006591fbb0 ffff8801213acb40 ffff8800806a2178
Mar 10 02:38:05 ocfs2test3 kernel:  ffff88006591fa30 ffffffff815d0d15 ffff88006591fba8 ffff88006591fad0
Mar 10 02:38:05 ocfs2test3 kernel: Call Trace:
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffff815d0d15>] schedule+0x35/0x80
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffff815d3545>] schedule_timeout+0x225/0x2b0
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffffa0590000>] ? 0xffffffffa0590000
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffffa05904a0>] ? ocfs2_control_read+0x50/0x50 [ocfs2_stack_user]
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffffa0590000>] ? 0xffffffffa0590000
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffff815d1617>] wait_for_completion+0x97/0xf0
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffff810918b0>] ? wake_up_q+0x80/0x80
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffffa06018d7>] __ocfs2_cluster_lock.isra.37+0x1a7/0x6b0 [ocfs2]
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffffa060276d>] ocfs2_inode_lock_full_nested+0x12d/0x840 [ocfs2]
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffffa05ffc59>] ? ocfs2_wake_downconvert_thread+0x49/0x50 [ocfs2]
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffffa0605c81>] ocfs2_permission+0x31/0xd0 [ocfs2]
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffff811ecd3e>] __inode_permission+0x5e/0xb0
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffff811ecda8>] inode_permission+0x18/0x50
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffff811ee2dc>] vfs_create+0x5c/0x120
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffff811f0825>] path_openat+0xee5/0x12e0
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffff811f1c8e>] do_filp_open+0x7e/0xd0
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffff8119aa77>] ? vma_merge+0x217/0x300
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffff811fe97f>] ? __alloc_fd+0x3f/0x170
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffff811e0ec5>] do_sys_open+0x115/0x1f0
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffff811e0fbe>] SyS_open+0x1e/0x20
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffff815d466e>] entry_SYSCALL_64_fastpath+0x12/0x71
Mar 10 02:38:05 ocfs2test3 kernel: INFO: task multi_reflink_t:13027 blocked for more than 480 seconds.
Mar 10 02:38:05 ocfs2test3 kernel:       Tainted: G            E   4.5.0-rc7-11-default #1
Mar 10 02:38:05 ocfs2test3 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Mar 10 02:38:05 ocfs2test3 kernel: multi_reflink_t D ffff88006591fa18     0 13027  13026 0x00000000
Mar 10 02:38:05 ocfs2test3 kernel:  ffff88006591fa18 ffff88008021cc80 ffff8801213acb40 ffff880065920000
Mar 10 02:38:05 ocfs2test3 kernel:  7fffffffffffffff ffff88006591fbb0 ffff8801213acb40 ffff8800806a2178
Mar 10 02:38:05 ocfs2test3 kernel:  ffff88006591fa30 ffffffff815d0d15 ffff88006591fba8 ffff88006591fad0
Mar 10 02:38:05 ocfs2test3 kernel: Call Trace:
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffff815d0d15>] schedule+0x35/0x80
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffff815d3545>] schedule_timeout+0x225/0x2b0
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffffa0590000>] ? 0xffffffffa0590000
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffffa05904a0>] ? ocfs2_control_read+0x50/0x50 [ocfs2_stack_user]
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffffa0590000>] ? 0xffffffffa0590000
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffff815d1617>] wait_for_completion+0x97/0xf0
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffff810918b0>] ? wake_up_q+0x80/0x80
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffffa06018d7>] __ocfs2_cluster_lock.isra.37+0x1a7/0x6b0 [ocfs2]
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffffa060276d>] ocfs2_inode_lock_full_nested+0x12d/0x840 [ocfs2]
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffffa05ffc59>] ? ocfs2_wake_downconvert_thread+0x49/0x50 [ocfs2]
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffffa0605c81>] ocfs2_permission+0x31/0xd0 [ocfs2]
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffff811ecd3e>] __inode_permission+0x5e/0xb0
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffff811ecda8>] inode_permission+0x18/0x50
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffff811ee2dc>] vfs_create+0x5c/0x120
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffff811f0825>] path_openat+0xee5/0x12e0
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffff811f1c8e>] do_filp_open+0x7e/0xd0
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffff8119aa77>] ? vma_merge+0x217/0x300
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffff811fe97f>] ? __alloc_fd+0x3f/0x170
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffff811e0ec5>] do_sys_open+0x115/0x1f0
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffff811e0fbe>] SyS_open+0x1e/0x20
Mar 10 02:38:05 ocfs2test3 kernel:  [<ffffffff815d466e>] entry_SYSCALL_64_fastpath+0x12/0x71
Mar 10 02:46:05 ocfs2test3 kernel: INFO: task multi_reflink_t:13027 blocked for more than 480 seconds.
Mar 10 02:46:05 ocfs2test3 kernel:       Tainted: G            E   4.5.0-rc7-11-default #1
Mar 10 02:46:05 ocfs2test3 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Mar 10 02:46:05 ocfs2test3 kernel: multi_reflink_t D ffff88006591fa18     0 13027  13026 0x00000000
Mar 10 02:46:05 ocfs2test3 kernel:  ffff88006591fa18 ffff88008021cc80 ffff8801213acb40 ffff880065920000
Mar 10 02:46:05 ocfs2test3 kernel:  7fffffffffffffff ffff88006591fbb0 ffff8801213acb40 ffff8800806a2178
Mar 10 02:46:05 ocfs2test3 kernel:  ffff88006591fa30 ffffffff815d0d15 ffff88006591fba8 ffff88006591fad0
Mar 10 02:46:05 ocfs2test3 kernel: Call Trace:
Mar 10 02:46:05 ocfs2test3 kernel:  [<ffffffff815d0d15>] schedule+0x35/0x80
Mar 10 02:46:05 ocfs2test3 kernel:  [<ffffffff815d3545>] schedule_timeout+0x225/0x2b0
Mar 10 02:46:05 ocfs2test3 kernel:  [<ffffffffa0590000>] ? 0xffffffffa0590000
Mar 10 02:46:05 ocfs2test3 kernel:  [<ffffffffa05904a0>] ? ocfs2_control_read+0x50/0x50 [ocfs2_stack_user]
Mar 10 02:46:05 ocfs2test3 kernel:  [<ffffffffa0590000>] ? 0xffffffffa0590000
Mar 10 02:46:05 ocfs2test3 kernel:  [<ffffffff815d1617>] wait_for_completion+0x97/0xf0
Mar 10 02:46:05 ocfs2test3 kernel:  [<ffffffff810918b0>] ? wake_up_q+0x80/0x80
Mar 10 02:46:05 ocfs2test3 kernel:  [<ffffffffa06018d7>] __ocfs2_cluster_lock.isra.37+0x1a7/0x6b0 [ocfs2]
Mar 10 02:46:05 ocfs2test3 kernel:  [<ffffffffa060276d>] ocfs2_inode_lock_full_nested+0x12d/0x840 [ocfs2]
Mar 10 02:46:05 ocfs2test3 kernel:  [<ffffffffa05ffc59>] ? ocfs2_wake_downconvert_thread+0x49/0x50 [ocfs2]
Mar 10 02:46:05 ocfs2test3 kernel:  [<ffffffffa0605c81>] ocfs2_permission+0x31/0xd0 [ocfs2]
Mar 10 02:46:05 ocfs2test3 kernel:  [<ffffffff811ecd3e>] __inode_permission+0x5e/0xb0
Mar 10 02:46:05 ocfs2test3 kernel:  [<ffffffff811ecda8>] inode_permission+0x18/0x50
Mar 10 02:46:05 ocfs2test3 kernel:  [<ffffffff811ee2dc>] vfs_create+0x5c/0x120
Mar 10 02:46:05 ocfs2test3 kernel:  [<ffffffff811f0825>] path_openat+0xee5/0x12e0
Mar 10 02:46:05 ocfs2test3 kernel:  [<ffffffff811f1c8e>] do_filp_open+0x7e/0xd0
Mar 10 02:46:05 ocfs2test3 kernel:  [<ffffffff8119aa77>] ? vma_merge+0x217/0x300
Mar 10 02:46:05 ocfs2test3 kernel:  [<ffffffff811fe97f>] ? __alloc_fd+0x3f/0x170
Mar 10 02:46:05 ocfs2test3 kernel:  [<ffffffff811e0ec5>] do_sys_open+0x115/0x1f0
Mar 10 02:46:05 ocfs2test3 kernel:  [<ffffffff811e0fbe>] SyS_open+0x1e/0x20
Mar 10 02:46:05 ocfs2test3 kernel:  [<ffffffff815d466e>] entry_SYSCALL_64_fastpath+0x12/0x71
Mar 10 02:54:05 ocfs2test3 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Mar 10 02:54:05 ocfs2test3 kernel: multi_reflink_t D ffff88006591fa18     0 13027  13026 0x00000000
Mar 10 02:54:05 ocfs2test3 kernel:  ffff88006591fa18 ffff88008021cc80 ffff8801213acb40 ffff880065920000
Mar 10 02:54:05 ocfs2test3 kernel:  7fffffffffffffff ffff88006591fbb0 ffff8801213acb40 ffff8800806a2178
Mar 10 02:54:05 ocfs2test3 kernel:  ffff88006591fa30 ffffffff815d0d15 ffff88006591fba8 ffff88006591fad0
Mar 10 02:54:05 ocfs2test3 kernel: Call Trace:
Mar 10 02:54:05 ocfs2test3 kernel:  [<ffffffff815d0d15>] schedule+0x35/0x80
Mar 10 02:54:05 ocfs2test3 kernel:  [<ffffffff815d3545>] schedule_timeout+0x225/0x2b0
Mar 10 02:54:05 ocfs2test3 kernel:  [<ffffffffa0590000>] ? 0xffffffffa0590000
Mar 10 02:54:05 ocfs2test3 kernel:  [<ffffffffa05904a0>] ? ocfs2_control_read+0x50/0x50 [ocfs2_stack_user]
Mar 10 02:54:05 ocfs2test3 kernel:  [<ffffffffa0590000>] ? 0xffffffffa0590000
Mar 10 02:54:05 ocfs2test3 kernel:  [<ffffffff815d1617>] wait_for_completion+0x97/0xf0
Mar 10 02:54:05 ocfs2test3 kernel:  [<ffffffff810918b0>] ? wake_up_q+0x80/0x80
Mar 10 02:54:05 ocfs2test3 kernel:  [<ffffffffa06018d7>] __ocfs2_cluster_lock.isra.37+0x1a7/0x6b0 [ocfs2]
Mar 10 02:54:05 ocfs2test3 kernel:  [<ffffffffa060276d>] ocfs2_inode_lock_full_nested+0x12d/0x840 [ocfs2]
Mar 10 02:54:05 ocfs2test3 kernel:  [<ffffffffa05ffc59>] ? ocfs2_wake_downconvert_thread+0x49/0x50 [ocfs2]
Mar 10 02:54:05 ocfs2test3 kernel:  [<ffffffffa0605c81>] ocfs2_permission+0x31/0xd0 [ocfs2]
Mar 10 02:54:05 ocfs2test3 kernel:  [<ffffffff811ecd3e>] __inode_permission+0x5e/0xb0
Mar 10 02:54:05 ocfs2test3 kernel:  [<ffffffff811ecda8>] inode_permission+0x18/0x50
Mar 10 02:54:05 ocfs2test3 kernel:  [<ffffffff811ee2dc>] vfs_create+0x5c/0x120
Mar 10 02:54:05 ocfs2test3 kernel:  [<ffffffff811f0825>] path_openat+0xee5/0x12e0
Mar 10 02:54:05 ocfs2test3 kernel:  [<ffffffff811f1c8e>] do_filp_open+0x7e/0xd0
Mar 10 02:54:05 ocfs2test3 kernel:  [<ffffffff8119aa77>] ? vma_merge+0x217/0x300
Mar 10 02:54:05 ocfs2test3 kernel:  [<ffffffff811fe97f>] ? __alloc_fd+0x3f/0x170
Mar 10 02:54:05 ocfs2test3 kernel:  [<ffffffff811e0ec5>] do_sys_open+0x115/0x1f0
Mar 10 02:54:05 ocfs2test3 kernel:  [<ffffffff811e0fbe>] SyS_open+0x1e/0x20
Mar 10 02:54:05 ocfs2test3 kernel:  [<ffffffff815d466e>] entry_SYSCALL_64_fastpath+0x12/0x71
renzhengeek commented 8 years ago

other threads on other nodes are all blocked at __ocfs2_cluster_lock!

ocfs2test1:~ # cat /proc/9544/stack [] path_openat+0x486/0x12e0 [] do_filp_open+0x7e/0xd0 [] do_sys_open+0x115/0x1f0 [] SyS_open+0x1e/0x20 [] entry_SYSCALL_64_fastpath+0x12/0x71 [] 0xffffffffffffffff

renzhengeek commented 8 years ago

Mar 16 13:32:21 ocfs2test1 sshd[22593]: pam_unix(sshd:session): session opened for user root by (uid=0) Mar 16 13:32:55 ocfs2test1 kernel: INFO: task multi_reflink_t:22094 blocked for more than 480 seconds. Mar 16 13:32:55 ocfs2test1 kernel: Tainted: G E 4.5.0-rc7-11-default #1 Mar 16 13:32:55 ocfs2test1 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Mar 16 13:32:55 ocfs2test1 kernel: multi_reflink_t D ffff88010798bca8 0 22094 22090 0x00000004 Mar 16 13:32:55 ocfs2test1 kernel: ffff88010798bca8 ffff880134030340 ffff880032cbc200 ffff88010798c000 Mar 16 13:32:55 ocfs2test1 kernel: ffff880032cbc200 ffff88003951459c 00000000ffffffff ffff8800395145a0 Mar 16 13:32:55 ocfs2test1 kernel: ffff88010798bcc0 ffffffff815d0d15 ffff880039514598 ffff88010798bcd0 Mar 16 13:32:55 ocfs2test1 kernel: Call Trace: Mar 16 13:32:55 ocfs2test1 kernel: [] schedule+0x35/0x80 Mar 16 13:32:55 ocfs2test1 kernel: [] schedule_preempt_disabled+0xe/0x10 Mar 16 13:32:55 ocfs2test1 kernel: [] mutex_lock_slowpath+0x8f/0x100 Mar 16 13:32:55 ocfs2test1 kernel: [] mutex_lock+0x17/0x27 Mar 16 13:32:55 ocfs2test1 kernel: [] filename_create+0x6b/0x150 Mar 16 13:32:55 ocfs2test1 kernel: [] user_path_create+0x2d/0x40 Mar 16 13:32:55 ocfs2test1 kernel: [] ocfs2_reflink_ioctl+0xc0/0x320 [ocfs2] Mar 16 13:32:55 ocfs2test1 kernel: [] ocfs2_ioctl+0x257/0x670 [ocfs2] Mar 16 13:32:55 ocfs2test1 kernel: [] ? kzfree+0x2d/0x30 Mar 16 13:32:55 ocfs2test1 kernel: [] do_vfs_ioctl+0x96/0x580 Mar 16 13:32:55 ocfs2test1 kernel: [] ? putname+0x53/0x60 Mar 16 13:32:55 ocfs2test1 kernel: [] SyS_ioctl+0x79/0x90 Mar 16 13:32:55 ocfs2test1 kernel: [] entry_SYSCALL_64_fastpath+0x12/0x71 Mar 16 13:32:55 ocfs2test1 kernel: INFO: task multi_reflink_t:22095 blocked for more than 480 seconds. Mar 16 13:32:55 ocfs2test1 kernel: Tainted: G E 4.5.0-rc7-11-default #1 Mar 16 13:32:55 ocfs2test1 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Mar 16 13:32:55 ocfs2test1 kernel: INFO: task multi_reflink_t:22095 blocked for more than 480 seconds. Mar 16 13:32:55 ocfs2test1 kernel: Tainted: G E 4.5.0-rc7-11-default #1 Mar 16 13:32:55 ocfs2test1 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Mar 16 13:32:55 ocfs2test1 kernel: multi_reflink_t D ffff880032c97838 0 22095 22090 0x00000000 Mar 16 13:32:55 ocfs2test1 kernel: ffff880032c97838 ffffffff81a0f4c0 ffff880107858100 ffff880032c98000 Mar 16 13:32:55 ocfs2test1 kernel: 7fffffffffffffff ffff880032c979d0 ffff880107858100 ffff880039514178 Mar 16 13:32:55 ocfs2test1 kernel: ffff880032c97850 ffffffff815d0d15 ffff880032c979c8 ffff880032c978f0 Mar 16 13:32:55 ocfs2test1 kernel: Call Trace: Mar 16 13:32:55 ocfs2test1 kernel: [] schedule+0x35/0x80 Mar 16 13:32:55 ocfs2test1 kernel: [] schedule_timeout+0x225/0x2b0 Mar 16 13:32:55 ocfs2test1 kernel: [] ? default_wake_function+0x12/0x20 Mar 16 13:32:55 ocfs2test1 kernel: [] ? autoremove_wake_function+0x12/0x40 Mar 16 13:32:55 ocfs2test1 kernel: [] ? wake_up_common+0x55/0x90 Mar 16 13:32:55 ocfs2test1 kernel: [] wait_for_completion+0x97/0xf0 Mar 16 13:32:55 ocfs2test1 kernel: [] ? wake_up_q+0x80/0x80 Mar 16 13:32:55 ocfs2test1 kernel: [] __ocfs2_cluster_lock.isra.37+0x1a7/0x6b0 [ocfs2] Mar 16 13:32:55 ocfs2test1 kernel: [] ? ocfs2_inode_cache_io_unlock+0x12/0x20 [ocfs2] Mar 16 13:32:55 ocfs2test1 kernel: [] ocfs2_inode_lock_full_nested+0x12d/0x840 [ocfs2] Mar 16 13:32:55 ocfs2test1 kernel: [] ? ocfs2_get_system_file_inode+0x60/0x2c0 [ocfs2] Mar 16 13:32:55 ocfs2test1 kernel: [] ocfs2_iop_get_acl+0x4f/0x279 [ocfs2] Mar 16 13:32:55 ocfs2test1 kernel: [] ? ocfs2_reserve_local_alloc_bits+0x63/0x290 [ocfs2] Mar 16 13:32:55 ocfs2test1 kernel: [] get_acl+0x41/0x60 Mar 16 13:32:55 ocfs2test1 kernel: [] posix_acl_create+0x5b/0x150 Mar 16 13:32:55 ocfs2test1 kernel: [] ocfs2_mknod+0x8ca/0x1370 [ocfs2] Mar 16 13:32:55 ocfs2test1 kernel: [] ocfs2_create+0x58/0x120 [ocfs2] Mar 16 13:32:55 ocfs2test1 kernel: [] vfs_create+0xc2/0x120 Mar 16 13:32:55 ocfs2test1 kernel: [] path_openat+0xee5/0x12e0 Mar 16 13:32:55 ocfs2test1 kernel: [] do_filp_open+0x7e/0xd0 Mar 16 13:32:55 ocfs2test1 kernel: [] ? vma_merge+0x217/0x300 Mar 16 13:32:55 ocfs2test1 kernel: [] ? __alloc_fd+0x3f/0x170 Mar 16 13:32:55 ocfs2test1 kernel: [] do_sys_open+0x115/0x1f0 Mar 16 13:32:55 ocfs2test1 kernel: [] SyS_open+0x1e/0x20 Mar 16 13:32:55 ocfs2test1 kernel: [] entry_SYSCALL_64_fastpath+0x12/0x71

renzhengeek commented 8 years ago

ocfs2test3:~ # cat /proc/2507/stack [] do_wait+0x1c6/0x240 [] SyS_wait4+0x64/0xc0 [] entry_SYSCALL_64_fastpath+0x12/0x71 [] 0xffffffffffffffff ocfs2test3:~ # cat /proc/2509/stack [] __ocfs2_cluster_lock.isra.37+0x1a7/0x6b0 [ocfs2] [] ocfs2_inode_lock_full_nested+0x12d/0x840 [ocfs2] [] ocfs2_iop_get_acl+0x4f/0x279 [ocfs2] [] get_acl+0x41/0x60 [] posix_acl_create+0x5b/0x150 [] ocfs2_mknod+0x8ca/0x1370 [ocfs2] [] ocfs2_create+0x58/0x120 [ocfs2] [] vfs_create+0xc2/0x120 [] path_openat+0xee5/0x12e0 [] do_filp_open+0x7e/0xd0 [] do_sys_open+0x115/0x1f0 [] SyS_open+0x1e/0x20 [] tracesys_phase2+0x84/0x89 [] 0xffffffffffffffff

renzhengeek commented 8 years ago

ocfs2test2:~ # cat /proc/2492/stack [] do_wait+0x1c6/0x240 [] SyS_wait4+0x64/0xc0 [] entry_SYSCALL_64_fastpath+0x12/0x71 [] 0xffffffffffffffff ocfs2test2:~ # cat /proc/2494/stack [] __ocfs2_cluster_lock.isra.37+0x1a7/0x6b0 [ocfs2] [] ocfs2_inode_lock_full_nested+0x12d/0x840 [ocfs2] [] ocfs2_mknod+0x21a/0x1370 [ocfs2] [] ocfs2_create+0x58/0x120 [ocfs2] [] vfs_create+0xc2/0x120 [] path_openat+0xee5/0x12e0 [] do_filp_open+0x7e/0xd0 [] do_sys_open+0x115/0x1f0 [] SyS_open+0x1e/0x20 [] tracesys_phase2+0x84/0x89 [] 0xffffffffffffffff

renzhengeek commented 8 years ago

gettimeofday({1458116737, 407538}, NULL) = 0 poll([{fd=5, events=POLLIN}, {fd=12, events=POLLIN}, {fd=15, events=POLLIN}, {fd=14, events=POLLIN}], 4, 0) = 0 (Timeout) clock_gettime(CLOCK_MONOTONIC, {538, 743610811}) = 0 gettimeofday({1458116737, 407703}, NULL) = 0 sched_yield() = 0 clock_gettime(CLOCK_MONOTONIC, {538, 743768953}) = 0 gettimeofday({1458116737, 407861}, NULL) = 0 poll([{fd=5, events=POLLIN}, {fd=12, events=POLLIN}, {fd=15, events=POLLIN}, {fd=14, events=POLLIN}], 4, 0) = 1 ([{fd=14, revents=POLLIN}]) clock_gettime(CLOCK_MONOTONIC, {538, 743938467}) = 0 gettimeofday({1458116737, 408031}, NULL) = 0 readv(14, [{"A\1\0\0\16\0\0\0", 8}, {"A\0\0\0\2\0\0\0\360\377\377\377\1\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 30720}], 2) = 22 poll([{fd=5, events=POLLIN}, {fd=12, events=POLLIN}, {fd=15, events=POLLIN}, {fd=14, events=POLLIN}], 4, 0) = 0 (Timeout) clock_gettime(CLOCK_MONOTONIC, {538, 744187352}) = 0 gettimeofday({1458116737, 408277}, NULL) = 0 sched_yield() = 0 writev(15, [{"A\1\0\0\16\0\0\0", 8}, {"A\0\0\0\3\0\0\0\360\377\377\377\1\0", 14}], 2) = 22 brk(0x1b46000) = 0x1b46000 brk(0x1d46000) = 0x1d46000 brk(0x1f46000) = 0x1f46000 open("/mnt/shared/ocfs2-multi-refcount-tests/multi_original_stress_refile_rank3_0", O_RDWR|O_CREAT, 0777) = 13 pwrite(13, "WXJBKGFBEDZQCHPAMCEHJLPHJWACBPFA"..., 32768, 0) = 32768 close(13) = 0 open("/mnt/shared/ocfs2-multi-refcount-tests/multi_original_stress_refile_rank3_0", O_RDONLY) = 13 ioctl(13, _IOC(_IOC_WRITE, 0x6f, 0x04, 0x18)) = 32768 close(15) = 0 open("/mnt/shared/ocfs2-multi-refcount-tests/multi_original_stress_refile_rank1_0", O_RDONLY) = 14 , 0x7ffcf2dc4cc0) = 0 close(13) = 0 open("/mnt/shared/ocfs2-multi-refcount-tests/multi_original_stress_refile_rank3_1", O_RDWR|O_CREAT, 0777pwrite(14, "RLDEAGPZYOGEHDZPQKZUSGMRKMGFFCFY"..., 32768, 0) = 15 ioctl(15, _IOC(_IOC_WRITE, 0x6f, 0x04, 0x18)) = 32768 close(14) = 0 open("/mnt/shared/ocfs2-multi-refcount-tests/multi_original_stress_refile_rank2_0", O_RDONLY) = 13 pwrite(13, "UWOOPAEHYNHWFUWUBRINNBWHFOXNSPBO"..., 32768, 0) = 14 ) = 32768 , 0x7ffe0122a2e0) = 0 close(15ioctl(14, _IOC(_IOC_WRITE, 0x6f, 0x04, 0x18)close(13) = 0 ) = 0 open("/mnt/shared/ocfs2-multi-refcount-tests/multi_original_stress_refile_rank3_1", O_RDONLYopen("/mnt/shared/ocfs2-multi-refcount-tests/multi_original_stress_refile_rank0_1", O_RDWR|O_CREAT, 0777) = 13 ioctl(13, _IOC(_IOC_WRITE, 0x6f, 0x04, 0x18), 0x7ffe97b0b8c0) = 0 close(15) = 0 open("/mnt/shared/ocfs2-multi-refcount-tests/multi_original_stress_refile_rank1_1", O_RDWR|O_CREAT, 0777) = 15 ) = 15 pwrite(15, "HGMYIVAEQAUCROXEHCDHCVDEJBJUJHIS"..., 32768, 0pwrite(15, "FCQYXJSTXGPUJHEPXBVTQLPRNQUCSXZY"..., 32768, 0) = 32768 close(15) = 32768 ) = 0 open("/mnt/shared/ocfs2-multi-refcount-tests/multi_original_stress_refile_rank1_1", O_RDONLYclose(15) = 0 open("/mnt/shared/ocfs2-multi-refcount-tests/multi_original_stress_refile_rank0_1", O_RDONLY, 0x7ffc77fcfd00) = 0 close(14) = 0 open("/mnt/shared/ocfs2-multi-refcount-tests/multi_original_stress_refile_rank2_1", O_RDWR|O_CREAT, 0777, 0x7ffcf2dc4cc0) = 0 close(13) = 0 open("/mnt/shared/ocfs2-multi-refcount-tests/multi_original_stress_refile_rank3_2", O_RDWR|O_CREAT, 0777) = 15 ) = 15 ioctl(15, _IOC(_IOC_WRITE, 0x6f, 0x04, 0x18)ioctl(15, _IOC(_IOC_WRITE, 0x6f, 0x04, 0x18)

renzhengeek commented 8 years ago 
4420 int ocfs2_reflink_ioctl(struct inode *inode,
4421                         const char __user *oldname,
4422                         const char __user *newname,
4423                         bool preserve)
4424 {
4425         struct dentry *new_dentry;
4426         struct path old_path, new_path;
4427         int error;
4428 
4429         if (!ocfs2_refcount_tree(OCFS2_SB(inode->i_sb)))
4430                 return -EOPNOTSUPP;
4431 
4432         error = user_path_at(AT_FDCWD, oldname, 0, &old_path);
4433         if (error) {
4434                 mlog_errno(error);
4435                 return error;
4436         }
4437 
4438         new_dentry = user_path_create(AT_FDCWD, newname, &new_path, 0);
4439         error = PTR_ERR(new_dentry);
4440         if (IS_ERR(new_dentry)) {
4441                 mlog_errno(error);
4442                 goto out;
4443         }
4444 
4445         error = -EXDEV;
4446         if (old_path.mnt != new_path.mnt) {
4447                 mlog_errno(error);
4448                 goto out_dput;
4449         }
renzhengeek commented 8 years ago

n1:4355:

id 00000006 gr PR rq IV pid 4355 master 0 "M0000000000000000000201cb6b1cc8"
id 0000000b gr EX rq IV pid 4355 master 0 "M00000000000000007e010100000000"
renzhengeek commented 8 years ago

n2:4195:

id 00000005 gr PR rq IV pid 4195 master 318951508 "M0000000000000000000201cb6b1cc8"
id 00000012 gr EX rq IV pid 4195 master 0 "M000000000000000003720100000000"
id 0000000c gr EX rq IV pid 4195 master 318951508 "M000000000000000000020bcb6b1cc8"
id 00000013 gr PR rq IV pid 4195 master 0 "O000000000000000003720100000000"
id 0000000f gr EX rq IV pid 4195 master 0 "W0000000000000000037201a2a20222"
id 00000014 gr PR rq IV pid 4195 master 0 "N00000000007e0101"
id 00000008 gr NL rq EX pid 4195 master 318951508 "M00000000000000007e010100000000"
renzhengeek commented 8 years ago

n3:4004

id 0000000f gr EX rq IV pid 4004 master 318951508 "M0000000000000000000207cb6b1cc8"
id 0000000c gr EX rq IV pid 4004 master 0 "M00000000000000007e0e0100000000"
id 0000000a gr EX rq IV pid 4004 master 0 "M000000000000000000020dcb6b1cc8"
id 0000000b gr EX rq IV pid 4004 master 0 "W00000000000000007e0e01508f4abb"
id 0000000e gr PR rq IV pid 4004 master 0 "N00000000007e0101"
id 0000000d gr PR rq IV pid 4004 master 0 "O00000000000000007e0e0100000000"
id 00000007 gr NL rq EX pid 4004 master 318951508 "M00000000000000007e010100000000"
renzhengeek commented 8 years ago 
ocfs2test2:~ # journalctl -r
-- Logs begin at Sat 2016-03-19 18:02:56 CST, end at Sat 2016-03-19 18:09:18 CST. --
Mar 19 18:09:18 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_free_ac_resource:143 ERROR: Global inode alloc: cluster unlock!!!
Mar 19 18:09:18 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_reserve_suballoc_bits:813 ERROR: alloc inode(523):slot(0): cluster locked                        !!!
Mar 19 18:09:18 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_reserve_suballoc_bits:804 ERROR: alloc inode(523):slot(0): wanting...                        !!!
Mar 19 18:09:18 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_free_ac_resource:143 ERROR: Global inode alloc: cluster unlock!!!
Mar 19 18:09:18 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_reserve_suballoc_bits:813 ERROR: alloc inode(523):slot(0): cluster locked                        !!!
Mar 19 18:09:18 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_reserve_suballoc_bits:804 ERROR: alloc inode(523):slot(0): wanting...                        !!!
Mar 19 18:09:18 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_reflink:4266 ERROR: Leaving ocfs2_create_inode_in_orphan...        !
Mar 19 18:09:18 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_create_inode_in_orphan:2652 ERROR: parent dir: cluster unlock
Mar 19 18:09:18 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_create_inode_in_orphan:2642 ERROR: inode alloc: cluster unlock
Mar 19 18:09:18 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_free_ac_resource:143 ERROR: Global inode alloc: cluster unlock!!!
Mar 19 18:09:18 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_prep_new_orphaned_file:2484 ERROR: Leaving ocfs2 reserve new inode...
Mar 19 18:09:18 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_reserve_new_inode:1113 ERROR: do we forget to release cluster lock of inode alloc???
Mar 19 18:09:18 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_reserve_new_inode:1097 ERROR: Leaving ocfs2_reserve_suballoc_bits with INODE_ALLOC_SYSTEM_INODE
Mar 19 18:09:18 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_reserve_suballoc_bits:813 ERROR: alloc inode(526):slot(0): cluster locked                        !!!
Mar 19 18:09:18 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_reserve_suballoc_bits:804 ERROR: alloc inode(526):slot(0): wanting...                        !!!
Mar 19 18:09:18 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_reserve_new_inode:1090 ERROR: Entering ocfs2_reserve_suballoc_bits with INODE_ALLOC_SYSTEM_INODE
Mar 19 18:09:18 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_prep_new_orphaned_file:2482 ERROR: Entring ocfs2 reserve new inode...
Mar 19 18:09:18 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_create_inode_in_orphan:2557 ERROR: parent dir(8257793): cluster locked                !
Mar 19 18:09:18 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_create_inode_in_orphan:2550 ERROR: parent dir(8257793): wanting...                !
Mar 19 18:09:18 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_reflink:4263 ERROR: Entring ocfs2_create_inode_in_orphan...        !
Mar 19 18:09:17 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_free_ac_resource:143 ERROR: Global inode alloc: cluster unlock!!!
Mar 19 18:09:17 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_reserve_suballoc_bits:813 ERROR: alloc inode(519):slot(4294967295): cluster locked                        !!!
Mar 19 18:09:17 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_reserve_suballoc_bits:804 ERROR: alloc inode(519):slot(4294967295): wanting...                        !!!
Mar 19 18:09:17 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_free_ac_resource:143 ERROR: Global inode alloc: cluster unlock!!!
Mar 19 18:09:17 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_mknod:520 ERROR: meta_ac: free alloc context....
Mar 19 18:09:17 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_mknod:514 ERROR: data_ac: free alloc context....
Mar 19 18:09:17 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_free_ac_resource:143 ERROR: Global inode alloc: cluster unlock!!!
Mar 19 18:09:17 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_mknod:509 ERROR: inode_ac: free alloc context....
Mar 19 18:09:17 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_mknod:496 ERROR: parent dir: cluster unlock
Mar 19 18:09:17 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_mknod:483 ERROR: dentry, inode: bound
Mar 19 18:09:17 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_mknod:479 ERROR: dentry: added
Mar 19 18:09:17 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_mknod:468 ERROR: dentry: lock attached
Mar 19 18:09:17 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_mknod:402 ERROR: ocfs2_mknod_locked....
Mar 19 18:09:17 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_mknod:368 ERROR: reserve clusters....
Mar 19 18:09:17 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_reserve_suballoc_bits:813 ERROR: alloc inode(523):slot(0): cluster locked                        !!!
Mar 19 18:09:17 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_reserve_suballoc_bits:804 ERROR: alloc inode(523):slot(0): wanting...                        !!!
Mar 19 18:09:17 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_mknod:360 ERROR: new metadate....
Mar 19 18:09:17 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_mknod:329 ERROR: new inode: inited
Mar 19 18:09:17 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_mknod:320 ERROR: new inode: reserved
Mar 19 18:09:17 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_reserve_new_inode:1113 ERROR: do we forget to release cluster lock of inode alloc???
Mar 19 18:09:17 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_reserve_new_inode:1097 ERROR: Leaving ocfs2_reserve_suballoc_bits with INODE_ALLOC_SYSTEM_INODE
Mar 19 18:09:17 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_reserve_suballoc_bits:813 ERROR: alloc inode(526):slot(0): cluster locked                        !!!
Mar 19 18:09:17 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_reserve_suballoc_bits:804 ERROR: alloc inode(526):slot(0): wanting...                        !!!
Mar 19 18:09:17 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_reserve_new_inode:1090 ERROR: Entering ocfs2_reserve_suballoc_bits with INODE_ALLOC_SYSTEM_INODE
Mar 19 18:09:17 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_mknod:280 ERROR: parent dir(8257793): cluster locked        !
Mar 19 18:09:17 ocfs2test2 kernel: (multi_reflink_t,2287,0):ocfs2_mknod:278 ERROR: parent dir(8257793): wanting...        !
renzhengeek commented 8 years ago 
Mar 19 18:09:18 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_mknod:368 ERROR: reserve clusters....
Mar 19 18:09:18 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_reserve_suballoc_bits:813 ERROR: alloc inode(524):slot(1): cluster locked                        !!!
Mar 19 18:09:18 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_reserve_suballoc_bits:804 ERROR: alloc inode(524):slot(1): wanting...                        !!!
Mar 19 18:09:18 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_mknod:360 ERROR: new metadate....
Mar 19 18:09:18 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_mknod:329 ERROR: new inode: inited
Mar 19 18:09:18 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_mknod:320 ERROR: new inode: reserved
Mar 19 18:09:18 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_reserve_new_inode:1113 ERROR: do we forget to release cluster lock of inode alloc???
Mar 19 18:09:18 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_reserve_new_inode:1097 ERROR: Leaving ocfs2_reserve_suballoc_bits with INODE_ALLOC_SYSTEM_INODE
Mar 19 18:09:18 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_reserve_suballoc_bits:813 ERROR: alloc inode(527):slot(1): cluster locked                        !!!
Mar 19 18:09:18 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_reserve_suballoc_bits:804 ERROR: alloc inode(527):slot(1): wanting...                        !!!
Mar 19 18:09:18 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_reserve_new_inode:1090 ERROR: Entering ocfs2_reserve_suballoc_bits with INODE_ALLOC_SYSTEM_INODE
Mar 19 18:09:18 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_mknod:280 ERROR: parent dir(8257793): cluster locked        !
Mar 19 18:09:18 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_mknod:278 ERROR: parent dir(8257793): wanting...        !
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_free_ac_resource:143 ERROR: Global inode alloc: cluster unlock!!!
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_reserve_suballoc_bits:813 ERROR: alloc inode(524):slot(1): cluster locked                        !!!
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_reserve_suballoc_bits:804 ERROR: alloc inode(524):slot(1): wanting...                        !!!
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_free_ac_resource:143 ERROR: Global inode alloc: cluster unlock!!!
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_reserve_suballoc_bits:813 ERROR: alloc inode(524):slot(1): cluster locked                        !!!
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_reserve_suballoc_bits:804 ERROR: alloc inode(524):slot(1): wanting...                        !!!
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_reflink:4266 ERROR: Leaving ocfs2_create_inode_in_orphan...        !
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_create_inode_in_orphan:2652 ERROR: parent dir: cluster unlock
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_create_inode_in_orphan:2642 ERROR: inode alloc: cluster unlock
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_free_ac_resource:143 ERROR: Global inode alloc: cluster unlock!!!
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_prep_new_orphaned_file:2484 ERROR: Leaving ocfs2 reserve new inode...
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_reserve_new_inode:1113 ERROR: do we forget to release cluster lock of inode alloc???
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_reserve_new_inode:1097 ERROR: Leaving ocfs2_reserve_suballoc_bits with INODE_ALLOC_SYSTEM_INODE
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_reserve_suballoc_bits:813 ERROR: alloc inode(527):slot(1): cluster locked                        !!!
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_reserve_suballoc_bits:804 ERROR: alloc inode(527):slot(1): wanting...                        !!!
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_reserve_new_inode:1090 ERROR: Entering ocfs2_reserve_suballoc_bits with INODE_ALLOC_SYSTEM_INODE
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_prep_new_orphaned_file:2482 ERROR: Entring ocfs2 reserve new inode...
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_create_inode_in_orphan:2557 ERROR: parent dir(8257793): cluster locked                !
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_create_inode_in_orphan:2550 ERROR: parent dir(8257793): wanting...                !
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_reflink:4263 ERROR: Entring ocfs2_create_inode_in_orphan...        !
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_free_ac_resource:143 ERROR: Global inode alloc: cluster unlock!!!
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_mknod:520 ERROR: meta_ac: free alloc context....
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_mknod:514 ERROR: data_ac: free alloc context....
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_free_ac_resource:143 ERROR: Global inode alloc: cluster unlock!!!
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_mknod:509 ERROR: inode_ac: free alloc context....
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_mknod:496 ERROR: parent dir: cluster unlock
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_mknod:483 ERROR: dentry, inode: bound
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_mknod:479 ERROR: dentry: added
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_mknod:468 ERROR: dentry: lock attached
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_mknod:402 ERROR: ocfs2_mknod_locked....
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_mknod:368 ERROR: reserve clusters....
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_reserve_suballoc_bits:813 ERROR: alloc inode(524):slot(1): cluster locked                        !!!
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_reserve_suballoc_bits:804 ERROR: alloc inode(524):slot(1): wanting...                        !!!
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_mknod:360 ERROR: new metadate....
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_mknod:329 ERROR: new inode: inited
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_mknod:320 ERROR: new inode: reserved
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_reserve_new_inode:1113 ERROR: do we forget to release cluster lock of inode alloc???
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_reserve_new_inode:1097 ERROR: Leaving ocfs2_reserve_suballoc_bits with INODE_ALLOC_SYSTEM_INODE
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_reserve_suballoc_bits:813 ERROR: alloc inode(527):slot(1): cluster locked                        !!!
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_reserve_suballoc_bits:804 ERROR: alloc inode(527):slot(1): wanting...                        !!!
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_reserve_new_inode:1090 ERROR: Entering ocfs2_reserve_suballoc_bits with INODE_ALLOC_SYSTEM_INODE
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_mknod:280 ERROR: parent dir(8257793): cluster locked        !
Mar 19 18:09:17 ocfs2test1 kernel: (multi_reflink_t,2426,0):ocfs2_mknod:278 ERROR: parent dir(8257793): wanting...        !
renzhengeek commented 8 years ago 
ocfs2test3:~ # journalctl -r
-- Logs begin at Sat 2016-03-19 18:03:05 CST, end at Sat 2016-03-19 18:09:18 CST. --
Mar 19 18:09:18 ocfs2test3 kernel: (multi_reflink_t,2392,0):ocfs2_free_ac_resource:143 ERROR: Global inode alloc: cluster unlock!!!
Mar 19 18:09:18 ocfs2test3 kernel: (multi_reflink_t,2392,0):ocfs2_reserve_suballoc_bits:813 ERROR: alloc inode(519):slot(4294967295): cluster locked                        !!!
Mar 19 18:09:18 ocfs2test3 kernel: (multi_reflink_t,2392,0):ocfs2_reserve_suballoc_bits:804 ERROR: alloc inode(519):slot(4294967295): wanting...                        !!!
Mar 19 18:09:18 ocfs2test3 kernel: (multi_reflink_t,2392,0):ocfs2_free_ac_resource:143 ERROR: Global inode alloc: cluster unlock!!!
Mar 19 18:09:18 ocfs2test3 kernel: (multi_reflink_t,2392,0):ocfs2_mknod:520 ERROR: meta_ac: free alloc context....
Mar 19 18:09:18 ocfs2test3 kernel: (multi_reflink_t,2392,0):ocfs2_mknod:514 ERROR: data_ac: free alloc context....
Mar 19 18:09:18 ocfs2test3 kernel: (multi_reflink_t,2392,0):ocfs2_free_ac_resource:143 ERROR: Global inode alloc: cluster unlock!!!
Mar 19 18:09:18 ocfs2test3 kernel: (multi_reflink_t,2392,0):ocfs2_mknod:509 ERROR: inode_ac: free alloc context....
Mar 19 18:09:18 ocfs2test3 kernel: (multi_reflink_t,2392,0):ocfs2_mknod:496 ERROR: parent dir: cluster unlock
Mar 19 18:09:18 ocfs2test3 kernel: (multi_reflink_t,2392,0):ocfs2_mknod:483 ERROR: dentry, inode: bound
Mar 19 18:09:18 ocfs2test3 kernel: (multi_reflink_t,2392,0):ocfs2_mknod:479 ERROR: dentry: added
Mar 19 18:09:18 ocfs2test3 kernel: (multi_reflink_t,2392,0):ocfs2_mknod:468 ERROR: dentry: lock attached
Mar 19 18:09:18 ocfs2test3 kernel: (multi_reflink_t,2392,0):ocfs2_mknod:402 ERROR: ocfs2_mknod_locked....
Mar 19 18:09:18 ocfs2test3 kernel: (multi_reflink_t,2392,0):ocfs2_mknod:368 ERROR: reserve clusters....
Mar 19 18:09:18 ocfs2test3 kernel: (multi_reflink_t,2392,0):ocfs2_reserve_suballoc_bits:813 ERROR: alloc inode(525):slot(2): cluster locked                        !!!
Mar 19 18:09:18 ocfs2test3 kernel: (multi_reflink_t,2392,0):ocfs2_reserve_suballoc_bits:804 ERROR: alloc inode(525):slot(2): wanting...                        !!!
Mar 19 18:09:18 ocfs2test3 kernel: (multi_reflink_t,2392,0):ocfs2_mknod:360 ERROR: new metadate....
Mar 19 18:09:18 ocfs2test3 kernel: (multi_reflink_t,2392,0):ocfs2_mknod:329 ERROR: new inode: inited
Mar 19 18:09:18 ocfs2test3 kernel: (multi_reflink_t,2392,0):ocfs2_mknod:320 ERROR: new inode: reserved
Mar 19 18:09:18 ocfs2test3 kernel: (multi_reflink_t,2392,0):ocfs2_reserve_new_inode:1113 ERROR: do we forget to release cluster lock of inode alloc???
Mar 19 18:09:18 ocfs2test3 kernel: (multi_reflink_t,2392,0):ocfs2_reserve_new_inode:1097 ERROR: Leaving ocfs2_reserve_suballoc_bits with INODE_ALLOC_SYSTEM_INODE
Mar 19 18:09:18 ocfs2test3 kernel: (multi_reflink_t,2392,0):ocfs2_reserve_suballoc_bits:813 ERROR: alloc inode(528):slot(2): cluster locked                        !!!
Mar 19 18:09:18 ocfs2test3 kernel: (multi_reflink_t,2392,0):ocfs2_reserve_suballoc_bits:804 ERROR: alloc inode(528):slot(2): wanting...                        !!!
Mar 19 18:09:18 ocfs2test3 kernel: (multi_reflink_t,2392,0):ocfs2_reserve_new_inode:1090 ERROR: Entering ocfs2_reserve_suballoc_bits with INODE_ALLOC_SYSTEM_INODE
Mar 19 18:09:18 ocfs2test3 kernel: (multi_reflink_t,2392,0):ocfs2_mknod:280 ERROR: parent dir(8257793): cluster locked        !
Mar 19 18:09:18 ocfs2test3 kernel: (multi_reflink_t,2392,0):ocfs2_mknod:278 ERROR: parent dir(8257793): wanting...        !
Mar 19 18:09:17 ocfs2test3 systemd[2361]: pam_unix(systemd-user:session): session opened for user ocfs2test by (uid=0)
renzhengeek commented 8 years ago

8257793

echo "stat " | debugfs.ocfs2 /dev/sda

renzhengeek commented 8 years ago 
ocfs2test1:~ # echo "locate <M00000000000000007e010100000000>" | debugfs.ocfs2 /dev/sda
debugfs.ocfs2 1.8.2
debugfs: locate <M00000000000000007e010100000000>
    8257793 /ocfs2-multi-refcount-tests/
debugfs: