[Devel] [PATCH RH7] fs/locks: add more info for unexpected lock

[Pavel Tikhomirov]

https://pmc.acronis.com/browse/TTASK-23738

[Wed May 16 11:22:02 2018] nfs: server 172.16.50.211 not responding, timed out
[Wed May 16 11:45:18 2018] ------------[ cut here ]------------
[Wed May 16 11:45:18 2018] WARNING: CPU: 8 PID: 14959 at fs/locks.c:2431 locks_remove_flock+0x1ea/0x200
[Wed May 16 11:45:18 2018] leftover lock: dev=0:44 ino=671023203 type=1 flags=0x1 start=9223372036854775805 end=9223372036854775805
...
[Thu May 17 13:40:10 2018] Tainting kernel with flag 0x9
[Thu May 17 13:40:10 2018] CPU: 0 PID: 47323 Comm: co_io ve: 0 Tainted: G        W      ------------   3.10.0-693.17.1.vz7.43.10 #1 43.10
[Thu May 17 13:40:10 2018] Hardware name: Microsoft Corporation Virtual Machine/Virtual Machine, BIOS 090006  05/23/2012
[Thu May 17 13:40:10 2018] Call Trace:
[Thu May 17 13:40:10 2018]  [<ffffffff816d5d81>] dump_stack+0x19/0x1b
[Thu May 17 13:40:10 2018]  [<ffffffff8108a402>] add_taint+0x32/0x70
[Thu May 17 13:40:10 2018]  [<ffffffff8108a8aa>] __warn+0xaa/0x100
[Thu May 17 13:40:10 2018]  [<ffffffff8108a95f>] warn_slowpath_fmt+0x5f/0x80
[Thu May 17 13:40:10 2018]  [<ffffffffc059c3ff>] ? nfs_flock+0x8f/0x110 [nfs]
[Thu May 17 13:40:10 2018]  [<ffffffff8127ae1a>] locks_remove_flock+0x1ea/0x200
[Thu May 17 13:40:10 2018]  [<ffffffff81220f6e>] __fput+0xce/0x2d0
[Thu May 17 13:40:10 2018]  [<ffffffff8122125e>] ____fput+0xe/0x10
[Thu May 17 13:40:10 2018]  [<ffffffff810b192f>] __task_work_run+0x8f/0xd0
[Thu May 17 13:40:10 2018]  [<ffffffff810a2045>] get_signal_to_deliver+0x545/0x5e0
[Thu May 17 13:40:10 2018]  [<ffffffffc059c2a5>] ? nfs_lock+0xd5/0x1a0 [nfs]
[Thu May 17 13:40:10 2018]  [<ffffffff812797a2>] ? vfs_lock_file+0x32/0x50
[Thu May 17 13:40:10 2018]  [<ffffffff81279849>] ? locks_remove_posix.part.27+0x89/0xc0
[Thu May 17 13:40:10 2018]  [<ffffffffc059bf6e>] ? nfs_file_fsync_commit+0x5e/0xd0 [nfs]
[Thu May 17 13:40:10 2018]  [<ffffffff8102a387>] do_signal+0x57/0x6b0
[Thu May 17 13:40:10 2018]  [<ffffffff81253313>] ? vfs_fsync_range+0x93/0x180
[Thu May 17 13:40:10 2018]  [<ffffffff810b1821>] ? task_work_add+0x51/0x60
[Thu May 17 13:40:10 2018]  [<ffffffff81220e48>] ? fput+0x58/0xb0
[Thu May 17 13:40:10 2018]  [<ffffffff8121c52b>] ? filp_close+0x5b/0x80
[Thu May 17 13:40:10 2018]  [<ffffffff8102aa3f>] do_notify_resume+0x5f/0xb0
[Thu May 17 13:40:10 2018]  [<ffffffff816e8db7>] int_signal+0x12/0x17

FL_POSIX lock is unexpectedly left locked, it was created for the struct
file we do __fput. It should've been already removed in
locks_remove_posix. Might be connected with nfs-server disconnect but
that does not reproduce manually. Need more info to investigate it.

Signed-off-by: Pavel Tikhomirov <ptikhomirov at virtuozzo.com>
---
 fs/locks.c | 8 ++++++--
 1 file changed, 6 insertions(+), 2 deletions(-)

diff --git a/fs/locks.c b/fs/locks.c
index b1667f364a9e..54c1d0ce979f 100644
--- a/fs/locks.c
+++ b/fs/locks.c
@@ -2424,11 +2424,15 @@ void locks_remove_flock(struct file *filp)
 			 * the list.
 			 */
 			WARN(!IS_FLOCK(fl),
-				"leftover lock: dev=%u:%u ino=%lu type=%hhd flags=0x%x start=%lld end=%lld\n",
+				"leftover lock: dev=%u:%u ino=%lu type=%hhd flags=0x%x start=%lld end=%lld "
+				"owner=%p counter=%d pid=%u ops=%p lmops=%p blocked=%d\n",
 				MAJOR(inode->i_sb->s_dev),
 				MINOR(inode->i_sb->s_dev), inode->i_ino,
 				fl->fl_type, fl->fl_flags,
-				fl->fl_start, fl->fl_end);
+				fl->fl_start, fl->fl_end,
+				fl->fl_owner, fl->fl_owner ? fl->fl_owner->count.counter : 0,
+				fl->fl_pid, fl->fl_ops, fl->fl_lmops,
+				!list_empty(&fl->fl_block));
 
 			locks_delete_lock(before, &dispose);
 			continue;
-- 
2.17.0