Re: A process killed while opening a file can result in leaked open handle on the server

[Ronnie Sahlberg <lsahlber@redhat.com>]

[-- Attachment #1: Type: text/plain, Size: 3309 bytes --]





----- Original Message -----
> From: "Frank Sorenson" <sorenson@redhat.com>
> To: "linux-cifs" <linux-cifs@vger.kernel.org>
> Sent: Wednesday, 13 November, 2019 5:34:27 AM
> Subject: A process killed while opening a file can result in leaked open handle on the server
> 
> If a process opening a file is killed while waiting for a SMB2_CREATE
> response from the server, the response may not be handled by the client,
> leaking an open file handle on the server.
> 
> This can be reproduced with the following:
> 
> # mount //vm3/user1 /mnt/vm3
> -overs=3,sec=ntlmssp,credentials=/root/.user1_smb_creds
> # cd /mnt/vm3
> # echo foo > foo
> 
> # for i in {1..100} ; do cat foo >/dev/null 2>&1 & sleep 0.0001 ; kill -9 $!
> ; done
> 
> (increase count if necessary--100 appears sufficient to cause multiple leaked
> file handles)
> 
> 
> The client will stop waiting for the response, and will output
> the following when the response does arrive:
> 
>     CIFS VFS: Close unmatched open
> 
> on the server side, an open file handle is leaked.  If using samba,
> the following will show these open files:
> 
> 
> # smbstatus | grep -i Locked -A1000
> Locked files:
> Pid          Uid        DenyMode   Access      R/W        Oplock
> SharePath   Name   Time
> --------------------------------------------------------------------------------------------------
> 25936        501        DENY_NONE  0x80        RDONLY     NONE
> /home/user1   .   Tue Nov 12 12:29:24 2019
> 25936        501        DENY_NONE  0x80        RDONLY     NONE
> /home/user1   .   Tue Nov 12 12:29:24 2019
> 25936        501        DENY_NONE  0x120089    RDONLY     LEASE(RWH)
> /home/user1   foo   Tue Nov 12 12:29:24 2019
> 25936        501        DENY_NONE  0x120089    RDONLY     LEASE(RWH)
> /home/user1   foo   Tue Nov 12 12:29:24 2019
> 25936        501        DENY_NONE  0x120089    RDONLY     LEASE(RWH)
> /home/user1   foo   Tue Nov 12 12:29:24 2019
> 25936        501        DENY_NONE  0x120089    RDONLY     LEASE(RWH)
> /home/user1   foo   Tue Nov 12 12:29:24 2019
> 25936        501        DENY_NONE  0x120089    RDONLY     LEASE(RWH)
> /home/user1   foo   Tue Nov 12 12:29:24 2019
> 
> 
> (also tracked https://bugzilla.redhat.com/show_bug.cgi?id=1771691)
> 

I don't think it has to do with "CIFS VFS: Close unmatched open", in fact those are probably the times
where it did not leak. Unless the SMB2_close() fails with an error.
Can you try the patch below and check that these SMB2_close() are successful?

I think it is more likely that we leak because we can not match the SMB2_Create() response with a MID.
Do you get "No task to wake, unknown frame received" in the log?

We need to do two things here.
1, Find out why we can not match this with a MID and second,
   This it to fix THIS bug.
2, In the demultiplex_thread, where we get a "No task to wake, unknown frame received" we should check
   is this an Open? if so we should invoke server->ops->handle_cancelled_mid()
   This is to make sure other similar bugs do not cause leaks like this.

regards
ronnie sahlberg


> Frank
> --
> Frank Sorenson
> sorenson@redhat.com
> Principal Software Maintenance Engineer
> Global Support Services - filesystems
> Red Hat
> 
> 

[-- Attachment #2: patch --]
[-- Type: text/x-patch, Size: 1575 bytes --]

diff --git a/fs/cifs/cifsglob.h b/fs/cifs/cifsglob.h
index d78bfcc19156..10cb4d4fb122 100644
--- a/fs/cifs/cifsglob.h
+++ b/fs/cifs/cifsglob.h
@@ -1548,6 +1548,7 @@ struct mid_q_entry {
 };
 
 struct close_cancelled_open {
+	__u64 mid;
 	struct cifs_fid         fid;
 	struct cifs_tcon        *tcon;
 	struct work_struct      work;
diff --git a/fs/cifs/smb2misc.c b/fs/cifs/smb2misc.c
index e311f58dc1c8..6120c307d88e 100644
--- a/fs/cifs/smb2misc.c
+++ b/fs/cifs/smb2misc.c
@@ -735,12 +735,19 @@ smb2_cancelled_close_fid(struct work_struct *work)
 {
 	struct close_cancelled_open *cancelled = container_of(work,
 					struct close_cancelled_open, work);
+	struct cifs_tcon *tcon = cancelled->tcon;
+	int rc;
 
-	cifs_dbg(VFS, "Close unmatched open\n");
+	cifs_tcon_dbg(VFS, "Close unmatched open for MID:%llx\n",
+		      cancelled->mid);
 
-	SMB2_close(0, cancelled->tcon, cancelled->fid.persistent_fid,
-		   cancelled->fid.volatile_fid);
-	cifs_put_tcon(cancelled->tcon);
+	rc = SMB2_close(0, tcon, cancelled->fid.persistent_fid,
+			cancelled->fid.volatile_fid);
+	if (rc) {
+		cifs_tcon_dbg(VFS, "Close cancelled mid failed with rc:%d\n", rc);
+	}
+
+	cifs_put_tcon(tcon);
 	kfree(cancelled);
 }
 
@@ -770,6 +777,7 @@ smb2_handle_cancelled_mid(char *buffer, struct TCP_Server_Info *server)
 	cancelled->fid.persistent_fid = rsp->PersistentFileId;
 	cancelled->fid.volatile_fid = rsp->VolatileFileId;
 	cancelled->tcon = tcon;
+	cancelled->mid = sync_hdr->MessageId;
 	INIT_WORK(&cancelled->work, smb2_cancelled_close_fid);
 	queue_work(cifsiod_wq, &cancelled->work);