Bug 998967
| Summary: | gluster 3.4.0 ACL returning different results with entity-timeout=0 and without | ||||||||||
|---|---|---|---|---|---|---|---|---|---|---|---|
| Product: | [Community] GlusterFS | Reporter: | Lukas Bezdicka <social> | ||||||||
| Component: | access-control | Assignee: | Nagaprasad Sathyanarayana <nsathyan> | ||||||||
| Status: | CLOSED CURRENTRELEASE | QA Contact: | |||||||||
| Severity: | unspecified | Docs Contact: | |||||||||
| Priority: | unspecified | ||||||||||
| Version: | 3.4.0 | CC: | barumuga, gluster-bugs, joe, jonathansteffan, kristof.wevers, ndevos, silas, smohan, spradhan | ||||||||
| Target Milestone: | --- | ||||||||||
| Target Release: | --- | ||||||||||
| Hardware: | Unspecified | ||||||||||
| OS: | Unspecified | ||||||||||
| Whiteboard: | |||||||||||
| Fixed In Version: | glusterfs-3.4.1 | Doc Type: | Bug Fix | ||||||||
| Doc Text: | Story Points: | --- | |||||||||
| Clone Of: | |||||||||||
| : | 1032984 (view as bug list) | Environment: | |||||||||
| Last Closed: | 2014-09-18 06:26:36 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: | |||||||||||
| Bug Depends On: | |||||||||||
| Bug Blocks: | 1032984 | ||||||||||
| Attachments: |
|
||||||||||
Created attachment 788468 [details]
mounted without entity-timeout=0
Created attachment 788469 [details]
printfs used to get debug output
*entity-timeout = entry-timeout entry-timeout=0: [2013-08-20 12:13:40.723671] T [fuse-bridge.c:1900:fuse_create_resume] 0-glusterfs-fuse: 965: CREATE /a6/15e83578ad5cba95c442273ea20bfa/tab_one.csv [2013-08-20 12:13:40.723754] E [posix-acl.c:244:acl_permits] 0-: mask_check 7 7 3 3 [2013-08-20 12:13:40.723766] T [posix-acl.c:246:acl_permits] 0-gluster-AC: tag: 16, perm: 7, id: -1 [2013-08-20 12:13:40.723773] E [posix-acl.c:269:acl_permits] 0-: verdict 1 [2013-08-20 12:13:40.723785] T [posix-acl.c:622:posix_acl_inherit] 0-gluster-AC: tag: 1, perm: 7, id: -1 [2013-08-20 12:13:40.723792] T [posix-acl.c:622:posix_acl_inherit] 0-gluster-AC: tag: 2, perm: 5, id: 26 [2013-08-20 12:13:40.723798] T [posix-acl.c:622:posix_acl_inherit] 0-gluster-AC: tag: 2, perm: 7, id: 48 [2013-08-20 12:13:40.723810] T [posix-acl.c:622:posix_acl_inherit] 0-gluster-AC: tag: 2, perm: 7, id: 91 [2013-08-20 12:13:40.723816] T [posix-acl.c:622:posix_acl_inherit] 0-gluster-AC: tag: 4, perm: 7, id: -1 [2013-08-20 12:13:40.723822] T [posix-acl.c:622:posix_acl_inherit] 0-gluster-AC: tag: 16, perm: 7, id: -1 [2013-08-20 12:13:40.723834] T [posix-acl.c:622:posix_acl_inherit] 0-gluster-AC: tag: 32, perm: 0, id: -1 [2013-08-20 12:13:40.723840] T [posix-acl.c:633:posix_acl_inherit] 0-gluster-AC: tag: 1, perm: 6, id: -1 [2013-08-20 12:13:40.723842] T [posix-acl.c:633:posix_acl_inherit] 0-gluster-AC: tag: 2, perm: 5, id: 26 [2013-08-20 12:13:40.723846] T [posix-acl.c:633:posix_acl_inherit] 0-gluster-AC: tag: 2, perm: 7, id: 48 [2013-08-20 12:13:40.723853] T [posix-acl.c:633:posix_acl_inherit] 0-gluster-AC: tag: 2, perm: 7, id: 91 [2013-08-20 12:13:40.723857] T [posix-acl.c:633:posix_acl_inherit] 0-gluster-AC: tag: 4, perm: 7, id: -1 [2013-08-20 12:13:40.723866] T [posix-acl.c:633:posix_acl_inherit] 0-gluster-AC: tag: 16, perm: 0, id: -1 [2013-08-20 12:13:40.723871] T [posix-acl.c:633:posix_acl_inherit] 0-gluster-AC: tag: 32, perm: 0, id: -1 [2013-08-20 12:13:40.723876] T [posix-acl.c:438:posix_acl_set] 0-gluster-AC: tag: 1, perm: 6, id: -1 [2013-08-20 12:13:40.723882] T [posix-acl.c:438:posix_acl_set] 0-gluster-AC: tag: 2, perm: 5, id: 26 [2013-08-20 12:13:40.723888] T [posix-acl.c:438:posix_acl_set] 0-gluster-AC: tag: 2, perm: 7, id: 48 [2013-08-20 12:13:40.723894] T [posix-acl.c:438:posix_acl_set] 0-gluster-AC: tag: 2, perm: 7, id: 91 [2013-08-20 12:13:40.723899] T [posix-acl.c:438:posix_acl_set] 0-gluster-AC: tag: 4, perm: 7, id: -1 [2013-08-20 12:13:40.723904] T [posix-acl.c:438:posix_acl_set] 0-gluster-AC: tag: 16, perm: 0, id: -1 [2013-08-20 12:13:40.723910] T [posix-acl.c:438:posix_acl_set] 0-gluster-AC: tag: 32, perm: 0, id: -1 ... [2013-08-20 12:13:40.732370] T [fuse-bridge.c:506:fuse_lookup_resume] 0-glusterfs-fuse: 980: LOOKUP /a6/15e83578ad5cba95c442273ea20bfa/tab_one.csv(e74fdda2-0605-4018-ba97-7f8f40631bf8) [2013-08-20 12:13:40.732462] E [posix-acl.c:244:acl_permits] 0-: mask_check 7 7 1 1 [2013-08-20 12:13:40.732476] T [posix-acl.c:246:acl_permits] 0-gluster-AC: tag: 16, perm: 7, id: -1 [2013-08-20 12:13:40.732483] E [posix-acl.c:269:acl_permits] 0-: verdict 1 [2013-08-20 12:13:40.732512] T [rpc-clnt.c:1302:rpc_clnt_record] 0-Staging-client-0: Auth Info: pid: 2478, uid: 48, gid: 48, owner: 0000000000000000 [2013-08-20 12:13:40.732524] T [rpc-clnt.c:1182:rpc_clnt_record_build_header] 0-rpc-clnt: Request fraglen 268, payload: 196, rpc hdr: 72 [2013-08-20 12:13:40.732762] T [rpc-clnt.c:1499:rpc_clnt_submit] 0-rpc-clnt: submitted request (XID: 0x1045x Program: GlusterFS 3.3, ProgVers: 330, Proc: 27) to rpc-transport (Staging-client-0) [2013-08-20 12:13:40.732786] T [rpc-clnt.c:669:rpc_clnt_reply_init] 0-Staging-client-0: received rpc message (RPC XID: 0x1045x Program: GlusterFS 3.3, ProgVers: 330, Proc: 27) from rpc-transport (Staging-client-0) [2013-08-20 12:13:40.732808] T [posix-acl.c:438:posix_acl_set] 0-gluster-AC: tag: 1, perm: 6, id: -1 [2013-08-20 12:13:40.732817] T [posix-acl.c:438:posix_acl_set] 0-gluster-AC: tag: 2, perm: 5, id: 26 [2013-08-20 12:13:40.732823] T [posix-acl.c:438:posix_acl_set] 0-gluster-AC: tag: 2, perm: 7, id: 48 [2013-08-20 12:13:40.732829] T [posix-acl.c:438:posix_acl_set] 0-gluster-AC: tag: 2, perm: 7, id: 91 [2013-08-20 12:13:40.732835] T [posix-acl.c:438:posix_acl_set] 0-gluster-AC: tag: 4, perm: 7, id: -1 [2013-08-20 12:13:40.732840] T [posix-acl.c:438:posix_acl_set] 0-gluster-AC: tag: 16, perm: 6, id: -1 [2013-08-20 12:13:40.732846] T [posix-acl.c:438:posix_acl_set] 0-gluster-AC: tag: 32, perm: 0, id: -1 [2013-08-20 12:13:40.732852] T [posix-acl.c:464:posix_acl_set] 0-gluster-OLDAC: tag: 1, perm: 6, id: -1 [2013-08-20 12:13:40.732858] T [posix-acl.c:464:posix_acl_set] 0-gluster-OLDAC: tag: 2, perm: 5, id: 26 [2013-08-20 12:13:40.732864] T [posix-acl.c:464:posix_acl_set] 0-gluster-OLDAC: tag: 2, perm: 7, id: 48 [2013-08-20 12:13:40.732870] T [posix-acl.c:464:posix_acl_set] 0-gluster-OLDAC: tag: 2, perm: 7, id: 91 [2013-08-20 12:13:40.732876] T [posix-acl.c:464:posix_acl_set] 0-gluster-OLDAC: tag: 4, perm: 7, id: -1 [2013-08-20 12:13:40.732881] T [posix-acl.c:464:posix_acl_set] 0-gluster-OLDAC: tag: 16, perm: 0, id: -1 [2013-08-20 12:13:40.732887] T [posix-acl.c:464:posix_acl_set] 0-gluster-OLDAC: tag: 32, perm: 0, id: -1 [2013-08-20 12:13:40.732900] T [fuse-bridge.c:376:fuse_entry_cbk] 0-glusterfs-fuse: 980: LOOKUP() /a6/15e83578ad5cba95c442273ea20bfa/tab_one.csv => -5001388607934358536 [2013-08-20 12:13:40.732933] T [posix-acl.c:811:posix_acl_lookup_cbk] 0-gluster-AC: tag: 1, perm: 6, id: -1 [2013-08-20 12:13:40.732943] T [posix-acl.c:811:posix_acl_lookup_cbk] 0-gluster-AC: tag: 2, perm: 5, id: 26 [2013-08-20 12:13:40.732950] T [posix-acl.c:811:posix_acl_lookup_cbk] 0-gluster-AC: tag: 2, perm: 7, id: 48 [2013-08-20 12:13:40.732955] T [posix-acl.c:811:posix_acl_lookup_cbk] 0-gluster-AC: tag: 2, perm: 7, id: 91 [2013-08-20 12:13:40.732961] T [posix-acl.c:811:posix_acl_lookup_cbk] 0-gluster-AC: tag: 4, perm: 7, id: -1 [2013-08-20 12:13:40.732967] T [posix-acl.c:811:posix_acl_lookup_cbk] 0-gluster-AC: tag: 16, perm: 6, id: -1 [2013-08-20 12:13:40.732973] T [posix-acl.c:811:posix_acl_lookup_cbk] 0-gluster-AC: tag: 32, perm: 0, id: -1 [2013-08-20 12:13:40.733001] T [fuse-resolve.c:51:fuse_resolve_loc_touchup] 0-fuse: return value inode_path 46 [2013-08-20 12:13:40.733027] T [fuse-bridge.c:1014:fuse_setattr_resume] 0-glusterfs-fuse: 981: SETATTR (140617569242828)/a6/15e83578ad5cba95c442273ea20bfa/tab_one.csv ... [2013-08-20 12:13:40.748972] T [fuse-bridge.c:1991:fuse_open_resume] 0-glusterfs-fuse: 988: OPEN /a6/15e83578ad5cba95c442273ea20bfa/tab_one.csv [2013-08-20 12:13:40.749074] E [posix-acl.c:244:acl_permits] 0-: mask_check 6 5 4 4 [2013-08-20 12:13:40.749087] T [posix-acl.c:246:acl_permits] 0-gluster-AC: tag: 16, perm: 6, id: -1 [2013-08-20 12:13:40.749094] E [posix-acl.c:269:acl_permits] 0-: verdict 1 [2013-08-20 12:13:40.749115] T [rpc-clnt.c:1302:rpc_clnt_record] 0-Staging-client-0: Auth Info: pid: 20027, uid: 26, gid: 26, owner: 0000000000000000 [2013-08-20 12:13:40.749126] T [rpc-clnt.c:1182:rpc_clnt_record_build_header] 0-rpc-clnt: Request fraglen 96, payload: 24, rpc hdr: 72 [2013-08-20 12:13:40.749310] T [rpc-clnt.c:1499:rpc_clnt_submit] 0-rpc-clnt: submitted request (XID: 0x1053x Program: GlusterFS 3.3, ProgVers: 330, Proc: 11) to rpc-transport (Staging-client-0) [2013-08-20 12:13:40.749332] T [rpc-clnt.c:669:rpc_clnt_reply_init] 0-Staging-client-0: received rpc message (RPC XID: 0x1053x Program: GlusterFS 3.3, ProgVers: 330, Proc: 11) from rpc-transport (Staging-client-0) [2013-08-20 12:13:40.749369] T [fuse-bridge.c:850:fuse_fd_cbk] 0-glusterfs-fuse: 988: OPEN() /a6/15e83578ad5cba95c442273ea20bfa/tab_one.csv => 0x1ce4d5c without entry-timeout=0: [2013-08-20 09:08:43.452800] T [fuse-bridge.c:1900:fuse_create_resume] 0-glusterfs-fuse: 467: CREATE /a6/15e83578ad5cba95c442273ea20bfa/tab_one.csv [2013-08-20 09:08:43.452906] E [posix-acl.c:244:acl_permits] 0-: mask_check 7 7 3 3 [2013-08-20 09:08:43.452921] T [posix-acl.c:246:acl_permits] 0-gluster-AC: tag: 16, perm: 7, id: -1 [2013-08-20 09:08:43.452926] E [posix-acl.c:269:acl_permits] 0-: verdict 1 [2013-08-20 09:08:43.452942] T [posix-acl.c:438:posix_acl_set] 0-gluster-AC: tag: 1, perm: 6, id: -1 [2013-08-20 09:08:43.452950] T [posix-acl.c:438:posix_acl_set] 0-gluster-AC: tag: 2, perm: 5, id: 26 [2013-08-20 09:08:43.452957] T [posix-acl.c:438:posix_acl_set] 0-gluster-AC: tag: 2, perm: 7, id: 48 [2013-08-20 09:08:43.452964] T [posix-acl.c:438:posix_acl_set] 0-gluster-AC: tag: 2, perm: 7, id: 91 [2013-08-20 09:08:43.452971] T [posix-acl.c:438:posix_acl_set] 0-gluster-AC: tag: 4, perm: 7, id: -1 [2013-08-20 09:08:43.452978] T [posix-acl.c:438:posix_acl_set] 0-gluster-AC: tag: 16, perm: 0, id: -1 [2013-08-20 09:08:43.452985] T [posix-acl.c:438:posix_acl_set] 0-gluster-AC: tag: 32, perm: 0, id: -1 [2013-08-20 09:08:43.453008] T [dht-common.c:4001:dht_create] 0-Staging-dht: creating /a6/15e83578ad5cba95c442273ea20bfa/tab_one.csv on Staging-client-0 [2013-08-20 09:08:43.453033] T [rpc-clnt.c:1302:rpc_clnt_record] 0-Staging-client-0: Auth Info: pid: 17129, uid: 48, gid: 48, owner: 0000000000000000 [2013-08-20 09:08:43.453046] T [rpc-clnt.c:1182:rpc_clnt_record_build_header] 0-rpc-clnt: Request fraglen 252, payload: 180, rpc hdr: 72 [2013-08-20 09:08:43.453093] T [rpc-clnt.c:1499:rpc_clnt_submit] 0-rpc-clnt: submitted request (XID: 0x525x Program: GlusterFS 3.3, ProgVers: 330, Proc: 23) to rpc-transport (Staging-client-0) [2013-08-20 09:08:43.454940] T [rpc-clnt.c:669:rpc_clnt_reply_init] 0-Staging-client-0: received rpc message (RPC XID: 0x525x Program: GlusterFS 3.3, ProgVers: 330, Proc: 23) from rpc-transport (Staging-client-0) [2013-08-20 09:08:43.454985] T [ioc-inode.c:192:ioc_inode_update] 0-Staging-io-cache: locked table(0x2591370) [2013-08-20 09:08:43.454997] T [ioc-inode.c:199:ioc_inode_update] 0-Staging-io-cache: unlocked table(0x2591370) [2013-08-20 09:08:43.455005] T [ioc-inode.c:202:ioc_inode_update] 0-Staging-io-cache: adding to inode_lru[1] [2013-08-20 09:08:43.455012] T [io-cache.c:645:ioc_create_cbk] 0-Staging-io-cache: locked inode(0x2612fd0) [2013-08-20 09:08:43.455019] T [io-cache.c:661:ioc_create_cbk] 0-Staging-io-cache: unlocked inode(0x2612fd0) [2013-08-20 09:08:43.455044] T [fuse-bridge.c:1775:fuse_create_cbk] 0-glusterfs-fuse: 467: CREATE() /a6/15e83578ad5cba95c442273ea20bfa/tab_one.csv => 0x25e7824 (ino=-7808569780882107263) ... [2013-08-20 09:08:43.459724] T [fuse-bridge.c:925:fuse_setattr_cbk] 0-glusterfs-fuse: 479: SETATTR() /a6/15e83578ad5cba95c442273ea20bfa/tab_one.csv => -7808569780882107263 [2013-08-20 09:08:43.459735] T [fuse-bridge.c:934:fuse_setattr_cbk] 0-glusterfs-fuse: fao: 10638174292827444353 243 1 10638174288957440436 140733193388033 48 227633266736 0 [2013-08-20 09:08:43.469582] T [fuse-resolve.c:51:fuse_resolve_loc_touchup] 0-fuse: return value inode_path 46 [2013-08-20 09:08:43.469615] T [fuse-bridge.c:1991:fuse_open_resume] 0-glusterfs-fuse: 481: OPEN /a6/15e83578ad5cba95c442273ea20bfa/tab_one.csv [2013-08-20 09:08:43.471138] E [posix-acl.c:244:acl_permits] 0-: mask_check 0 5 4 0 [2013-08-20 09:08:43.471171] T [posix-acl.c:246:acl_permits] 0-gluster-AC: tag: 16, perm: 0, id: -1 [2013-08-20 09:08:43.471183] E [posix-acl.c:269:acl_permits] 0-: verdict 0 [2013-08-20 09:08:43.471200] W [fuse-bridge.c:875:fuse_fd_cbk] 0-glusterfs-fuse: 481: OPEN() /a6/15e83578ad5cba95c442273ea20bfa/tab_one.csv => -1 (Permission denied) so the change of acl after LOOKUP on tab_one was responsible for: [2013-08-20 12:13:40.732840] T [posix-acl.c:438:posix_acl_set] 0-gluster-AC: tag: 16, perm: 6, id: -1 which got evaluated during OPEN in acl_permits: [2013-08-20 12:13:40.749087] T [posix-acl.c:246:acl_permits] 0-gluster-AC: tag: 16, perm: 6, id: -1 while without LOOKUP it stayed on: [2013-08-20 09:08:43.452978] T [posix-acl.c:438:posix_acl_set] 0-gluster-AC: tag: 16, perm: 0, id: -1 and ended up as: [2013-08-20 09:08:43.471171] T [posix-acl.c:246:acl_permits] 0-gluster-AC: tag: 16, perm: 0, id: -1 volume options set in order to cleanup debug: Options Reconfigured: server.statedump-path: /mnt/tmp diagnostics.latency-measurement: On diagnostics.brick-log-level: WARNING diagnostics.count-fop-hits: On diagnostics.client-log-level: TRACE nfs.disable: On performance.cache-refresh-timeout: 0 performance.md-cache-timeout: 0 performance.io-cache: off performance.open-behind: off performance.quick-read: off performance.stat-prefetch: off performance.flush-behind: off REVIEW: http://review.gluster.org/5693 (mount/fuse: invalidate entry upon setattr) posted (#1) for review on master by Lubomir Rintel (lubo.rintel) REVIEW: http://review.gluster.org/5979 (posix-acl: fixup extended ACL entries properly) posted (#1) for review on master by Anand Avati (avati) REVIEW: http://review.gluster.org/5979 (posix-acl: fixup extended ACL entries properly) posted (#2) for review on master by Anand Avati (avati) REVIEW: http://review.gluster.org/5979 (posix-acl: fixup extended ACL entries properly) posted (#3) for review on master by Anand Avati (avati) COMMIT: http://review.gluster.org/5979 committed in master by Vijay Bellur (vbellur) ------ commit 8737b4697ad555a1e49ef87b5d439bfb74d8b5b5 Author: Anand Avati <avati> Date: Sun Sep 15 15:00:06 2013 -0700 posix-acl: fixup extended ACL entries properly Typically when updating cached ACL from backend, we get both iatt and ACL xattrs (like lookup, readdirplus etc.) However in calls like setattr(), the mode would have updated but we receive only iatt and not the ACL xattrs. In such case we need to "spread" the effects of the changed mode properly into the cached ACL xattr ourselves. Change-Id: I23a7bc9c14722ff6848e175ed4bbe863a21ce2c9 BUG: 998967 Signed-off-by: Anand Avati <avati> Reviewed-on: http://review.gluster.org/5979 Tested-by: Gluster Build System <jenkins.com> Reviewed-by: Amar Tumballi <amarts> REVIEW: http://review.gluster.org/6002 (posix-acl: fixup extended ACL entries properly) posted (#1) for review on release-3.4 by Anand Avati (avati) COMMIT: http://review.gluster.org/6002 committed in release-3.4 by Anand Avati (avati) ------ commit 56769c4db9e25f10c35b7f9b6ccf24dc27b35f07 Author: Anand Avati <avati> Date: Sun Sep 15 15:00:06 2013 -0700 posix-acl: fixup extended ACL entries properly Typically when updating cached ACL from backend, we get both iatt and ACL xattrs (like lookup, readdirplus etc.) However in calls like setattr(), the mode would have updated but we receive only iatt and not the ACL xattrs. In such case we need to "spread" the effects of the changed mode properly into the cached ACL xattr ourselves. Change-Id: I23a7bc9c14722ff6848e175ed4bbe863a21ce2c9 BUG: 998967 Signed-off-by: Anand Avati <avati> Reviewed-on: http://review.gluster.org/6002 Tested-by: Gluster Build System <jenkins.com> *** Bug 991035 has been marked as a duplicate of this bug. *** glusterfs-3.4.1, glusterfs-3.5 and newer contain these fixes. Please re-open this bug if the problem has not been fixed correctly. *** Bug 1032984 has been marked as a duplicate of this bug. *** |
Created attachment 788467 [details] mounted with entity-timeout=0 Description of problem: Gluster patched with patches promoted to 3.4.1 Version-Release number of selected component (if applicable): gluster 3.4.0 with: 1feaebfe0ae140ecafd5c37a0ce1bb5f0a1ac0cf abd9f490f5aa45ab4f0a69cf0cb56b4847324373 591f2c1aee6aa2be34114028537d0aecfe1ccda5 88128728187e1d3216e0df1092d725311317fc9e 9287a95c2cb40ff1d2eed4c6789176d837e21a85 e5154f2dd81ec24c6ce757a8c491b9ecda118df2 b3e03f1a8c2cb3e02c332c553a1cc261eb76c4fb fd9c3d3f3daa0928524c807d2177e95957421833 435854f7c14beccc76df09a06e9c813180a8cb39 How reproducible: always Steps to Reproduce: We have hard reproducer, nothing small yet :/ Actual results: We have long test where we detele whole structure, recreate it, upload files via apache, delete them, upload them again, try to read them from postgress and process them. In this case file tab_one.csv gets uploaded, deleted uploaded and read by postgres. With entity-timeout=0 option to gluster mount everything works fine without it we get Permission denied. From printing out ACLS I can see that they are set differently on client and on server while entity-timeout causes ACLs to be taken from server. without entity-timouet I can see (see file kwas) with entity-timeout I can see (see file kwak) Expected results: permissions are same on client and server Additional info: