Bug 1594604

Summary: CephFS Client library (ceph-fuse) drops incorrect caps during setattr
Product: [Red Hat Storage] Red Hat Ceph Storage Reporter: Patrick Donnelly <pdonnell>
Component: CephFSAssignee: Patrick Donnelly <pdonnell>
Status: CLOSED ERRATA QA Contact: Tejas <tchandra>
Severity: low Docs Contact:
Priority: low    
Version: 3.0CC: ceph-eng-bugs, ceph-qe-bugs, john.spray, rperiyas, tchandra
Target Milestone: z5   
Target Release: 3.0   
Hardware: All   
OS: All   
Whiteboard:
Fixed In Version: RHEL: ceph-12.2.4-32 Ubuntu: ceph_12.2.4-36redhat1xenial Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2018-08-09 18:27:13 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Patrick Donnelly 2018-06-24 23:03:54 UTC
Description of problem:

Client unnecessarily drops auth shared caps when doing setattr of the mtime/atime or the file size (truncate).

Version-Release number of selected component (if applicable):

3.0

How reproducible:

100%

Steps to Reproduce:
1. Compile this libcephfs C++ program:

> #include <stddef.h>
> #include <utime.h>
> #include "include/cephfs/libcephfs.h"
> 
> int main (int argc, char *argv[])
> { 
>   struct ceph_mount_info *admin;
>   struct utimbuf times;
> 
>   int r = ceph_create(&admin, NULL);
>   if (r < 0)
>     return r;
>   ceph_conf_read_file(admin, NULL);
>   ceph_conf_parse_env(admin, NULL);
>   r = ceph_mount(admin, "/");
>   if (r < 0)
>     return r;
> 
>   ceph_mkdir(admin, "foo", 0777);
>   ceph_symlink(admin, "target", "foo/bar");
>   ceph_utime(admin, "foo", &times);
> 
>   ceph_shutdown(admin);
>   return 0;
> }


2. Run it against a test cluster and look at the logs.

Actual results:

Observe in the debug log that the As caps were dropped as part of the setattr request to the MDS:

> 2018-06-24 22:48:39.528142 7f14f4d10480 10 client.4168 _setattr mask 24 issued pAsLsXsFs
> 2018-06-24 22:48:39.528147 7f14f4d10480 15 inode.get on 0x7f14b8010700 0x10000000000.head now 4
> 2018-06-24 22:48:39.528150 7f14f4d10480 20 client.4168 choose_target_mds starting with req->inode 0x10000000000.head(faked_ino=0 ref=4 ll_ref=0 cap_refs={} open={} mode=40777 size=0/0 mtime=2018-06-24 22:48:39.510289 caps=pAsLsXsFs(0=pAsLsXsFs) parents=0x20a7e40 0x7f14b8010700)
> 2018-06-24 22:48:39.528162 7f14f4d10480 20 client.4168 choose_target_mds 0x10000000000.head(faked_ino=0 ref=4 ll_ref=0 cap_refs={} open={} mode=40777 size=0/0 mtime=2018-06-24 22:48:39.510289 caps=pAsLsXsFs(0=pAsLsXsFs) parents=0x20a7e40 0x7f14b8010700) is_hash=0 hash=0
> 2018-06-24 22:48:39.528172 7f14f4d10480 10 client.4168 choose_target_mds from caps on inode 0x10000000000.head(faked_ino=0 ref=4 ll_ref=0 cap_refs={} open={} mode=40777 size=0/0 mtime=2018-06-24 22:48:39.510289 caps=pAsLsXsFs(0=pAsLsXsFs) parents=0x20a7e40 0x7f14b8010700)
> 2018-06-24 22:48:39.528181 7f14f4d10480 20 client.4168 mds is 0
> 2018-06-24 22:48:39.528183 7f14f4d10480 10 client.4168 send_request rebuilding request 5 for mds.0
> 2018-06-24 22:48:39.528186 7f14f4d10480 20 client.4168 encode_cap_releases enter (req: 0x20afa00, mds: 0)
> 2018-06-24 22:48:39.528188 7f14f4d10480 20 client.4168 encode_inode_release enter(in:0x10000000000.head(faked_ino=0 ref=4 ll_ref=0 cap_refs={} open={} mode=40777 size=0/0 mtime=2018-06-24 22:48:39.510289 caps=pAsLsXsFs(0=pAsLsXsFs) parents=0x20a7e40 0x7f14b8010700), req:0x20afa00 mds:0, drop:7172, unless:0, have:, force:0)
> 2018-06-24 22:48:39.528200 7f14f4d10480 20 client.4168 send_request set sent_stamp to 2018-06-24 22:48:39.528200
> 2018-06-24 22:48:39.528203 7f14f4d10480 10 client.4168 send_request client_request(unknown.0:5 setattr mtime=4196368.000000 atime=4196816.000000 #0x10000000000 2018-06-24 22:48:39.528149 caller_uid=0, caller_gid=0{}) v4 to mds.0
> 2018-06-24 22:48:39.528209 7f14f4d10480  1 -- 127.0.0.1:0/2173081769 --> 127.0.0.1:6814/1313111344 -- client_request(unknown.0:5 setattr mtime=4196368.000000 atime=4196816.000000 #0x10000000000 2018-06-24 22:48:39.528149 caller_uid=0, caller_gid=0{}) v4 -- 0x20b0420 con 0
> 2018-06-24 22:48:39.528235 7f14f4d10480 20 client.4168 awaiting reply|forward|kick on 0x7ffe2ea3a5e0
> 2018-06-24 22:48:39.529855 7f14cdffb700  1 -- 127.0.0.1:0/2173081769 <== mds.0 127.0.0.1:6814/1313111344 7 ==== client_caps(revoke ino 0x10000000000 8 seq 3 caps=pLsXs dirty=- wanted=- follows 0 size 0/0 ts 1/18446744073709551615 mtime 2018-06-24 22:48:39.510289 tws 1) v10 ==== 236+0+0 (232362218 0 0) 0x7f14d4002390 con 0x20a39f0

Expected results:

> 2018-06-24 22:55:32.807938 7ff706145480 10 client.4184 _setattr mask 24 issued pAsLsXs
> 2018-06-24 22:55:32.807943 7ff706145480 15 inode.get on 0x7ff6c8010730 0x10000000000.head now 5
> 2018-06-24 22:55:32.807946 7ff706145480 20 client.4184 choose_target_mds starting with req->inode 0x10000000000.head(faked_ino=0 ref=5 ll_ref=0 cap_refs={} open={} mode=40777 size=0/0 mtime=4196368.000000 caps=pAsLsXs(0=pAsLsXs) parents=0x9a6200 0x7ff6c8010730)
> 2018-06-24 22:55:32.807961 7ff706145480 20 client.4184 choose_target_mds 0x10000000000.head(faked_ino=0 ref=5 ll_ref=0 cap_refs={} open={} mode=40777 size=0/0 mtime=4196368.000000 caps=pAsLsXs(0=pAsLsXs) parents=0x9a6200 0x7ff6c8010730) is_hash=0 hash=0
> 2018-06-24 22:55:32.807969 7ff706145480 10 client.4184 choose_target_mds from caps on inode 0x10000000000.head(faked_ino=0 ref=5 ll_ref=0 cap_refs={} open={} mode=40777 size=0/0 mtime=4196368.000000 caps=pAsLsXs(0=pAsLsXs) parents=0x9a6200 0x7ff6c8010730)
> 2018-06-24 22:55:32.807976 7ff706145480 20 client.4184 mds is 0
> 2018-06-24 22:55:32.807978 7ff706145480 10 client.4184 send_request rebuilding request 5 for mds.0
> 2018-06-24 22:55:32.807981 7ff706145480 20 client.4184 encode_cap_releases enter (req: 0x9b4980, mds: 0)
> 2018-06-24 22:55:32.807983 7ff706145480 20 client.4184 encode_inode_release enter(in:0x10000000000.head(faked_ino=0 ref=5 ll_ref=0 cap_refs={} open={} mode=40777 size=0/0 mtime=4196368.000000 caps=pAsLsXs(0=pAsLsXs) parents=0x9a6200 0x7ff6c8010730), req:0x9b4980 mds:0, drop:7424, unless:0, have:, force:0)
> 2018-06-24 22:55:32.807992 7ff706145480 20 client.4184 send_request set sent_stamp to 2018-06-24 22:55:32.807992
> 2018-06-24 22:55:32.807995 7ff706145480 10 client.4184 send_request client_request(unknown.0:5 setattr mtime=4196368.000000 atime=4196816.000000 #0x10000000000 2018-06-24 22:55:32.807944 caller_uid=0, caller_gid=0{}) v4 to mds.0
> 2018-06-24 22:55:32.808002 7ff706145480  1 -- 127.0.0.1:0/822859593 --> 127.0.0.1:6814/1313111344 -- client_request(unknown.0:5 setattr mtime=4196368.000000 atime=4196816.000000 #0x10000000000 2018-06-24 22:55:32.807944 caller_uid=0, caller_gid=0{}) v4 -- 0x9b5370 con 0
> 2018-06-24 22:55:32.808025 7ff706145480 20 client.4184 awaiting reply|forward|kick on 0x7ffd92cbb800
> 2018-06-24 22:55:32.808106 7ff6da7fc700 10 client.4184 put_inode on 0x10000000000.head(faked_ino=0 ref=5 ll_ref=0 cap_refs={} open={} mode=40777 size=0/0 mtime=4196368.000000 caps=pAsLsXs(0=pAsLsXs) parents=0x9a6200 0x7ff6c8010730)


Additional info:

Observe that the As caps were dropped as part of the setattr request to the MDS. They should not be dropped.

Comment 10 errata-xmlrpc 2018-08-09 18:27:13 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2018:2375