Actions
Bug #49912
closedclient: dir->dentries inconsistent, both newname and oldname points to same inode, mv complains "are the same file"
Status:
Resolved
Priority:
High
Assignee:
Category:
Correctness/Safety
Target version:
% Done:
0%
Source:
Community (dev)
Tags:
backport_processed
Backport:
pacific, quincy, reef
Regression:
No
Severity:
2 - major
Reviewed:
Affected Versions:
ceph-qa-suite:
Component(FS):
Client, ceph-fuse
Labels (FS):
Pull request ID:
Crash signature (v1):
Crash signature (v2):
Description
we have an applications that use FS as a lock --- an empty file named .dw_gem2_cmn_sd_{INPROGRESS/COMPLETE} , application use mv that move from .dw_gem2_cmn_sd_INPROGRESS to .dw_gem2_cmn_sd_COMPLETE and reverse. Sometimes the mv complains .dw_gem2_cmn_sd_INPROGRESS and .dw_gem2_cmn_sd_COMPLETE are the same file. ls is good however stat both INPROGRESS and COMPLETE returns same inode.
bash-4.2# ls -ialh total 7.0K 5497578360817 drwxr-xr-x 2 dw_adm dw_ops 2.1K Mar 21 05:18 . 4398051190604 drwxrwxr-x 5 dw_adm dw_ops 4.2K Mar 3 10:36 .. 5497607496142 -rw-r--r-- 1 dw_adm dw_ops 159 Mar 21 03:47 .dw_gem2_cmn_actvty_cd_COMPLETE 5497607496143 -rw-r--r-- 1 dw_adm dw_ops 158 Mar 21 03:09 .dw_gem2_cmn_adj_rvnu_i_COMPLETE 5497661531523 -rw-r--r-- 1 dw_adm dw_ops 177 Mar 21 03:32 .dw_gem2_cmn_adj_rvnu_i_etrs_COMPLETE 5497607496144 -rw-r--r-- 1 dw_adm dw_ops 166 Mar 21 05:10 .dw_gem2_cmn_ck_i_COMPLETE 5497607496145 -rw-r--r-- 1 dw_adm dw_ops 156 Mar 21 03:20 .dw_gem2_cmn_lstg_i_COMPLETE 5497607496146 -rw-r--r-- 1 dw_adm dw_ops 154 Mar 21 03:09 .dw_gem2_cmn_rvnu_i_COMPLETE 5497661523504 -rw-r--r-- 1 dw_adm dw_ops 169 Mar 21 03:32 .dw_gem2_cmn_rvnu_i_etrs_COMPLETE 5497653129440 -rw-r--r-- 1 dw_adm dw_ops 177 Dec 7 23:53 .dw_gem2_cmn_sap_sd_INPROGRESS 5497607496147 -rw-r--r-- 1 dw_adm dw_ops 163 Mar 21 05:18 .dw_gem2_cmn_sd_INPROGRESS 5497578827365 -rw-r--r-- 1 dw_adm dw_ops 187 Mar 2 10:08 .gem2_cmn_aum_off_pltfrm_cm_COMPLETE 5497578360826 -rw-r--r-- 1 dw_adm dw_ops 201 Mar 14 10:07 .gem2_cmn_aum_off_pltfrm_cw_COMPLETE 5497607496148 -rw-r--r-- 1 dw_adm dw_ops 191 Mar 21 03:10 .gem2_cmn_off_pltfrm_i_COMPLETE bash-4.2# stat .dw_gem2_cmn_sd_INPROGRESS File: ‘.dw_gem2_cmn_sd_INPROGRESS’ Size: 163 Blocks: 1 IO Block: 4194304 regular file Device: 92h/146d Inode: 5497607496147 Links: 1 Access: (0644/-rw-r--r--) Uid: ( 506/ dw_adm) Gid: ( 21/ dw_ops) Access: 2020-03-31 20:44:17.108239682 -0700 Modify: 2021-03-21 05:18:47.373138099 -0700 Change: 2021-03-21 05:18:47.373138099 -0700 Birth: - bash-4.2# stat .dw_gem2_cmn_sd_COMPLETE File: ‘.dw_gem2_cmn_sd_COMPLETE’ Size: 163 Blocks: 1 IO Block: 4194304 regular file Device: 92h/146d Inode: 5497607496147 Links: 1 Access: (0644/-rw-r--r--) Uid: ( 506/ dw_adm) Gid: ( 21/ dw_ops) Access: 2020-03-31 20:44:17.108239682 -0700 Modify: 2021-03-21 05:18:47.373138099 -0700 Change: 2021-03-21 05:18:47.373138099 -0700 Birth: -
We debugged into the issue, see below, the dn of the inode 0x50002f121d3 should be .dw_gem2_cmn_sd_INPROGRESS(see the dump inode from mds), when ls, it reads from dir->readdir_cache, however when doing the stat, it checks the dn from dir->dentries, the .dw_gem2_cmn_sd_COMPLETE still exists in the dn (which it should not), and as the inode satisfy CEPH_STAT_CAP_INODE_ALL(the the dump inode result below), it returns the cache result.
dropping the dentry/inode cache by echo 2> /proc/sys/vm/drop_caches and redo the stat .dw_gem2_cmn_sd_COMPLETE get properly -2(right result)
if (dir->caps_issued_mask(CEPH_CAP_FILE_SHARED, true)) {
if (dn->cap_shared_gen == dir->shared_gen &&
(!dn->inode || dn->inode->caps_issued_mask(mask, true)))
goto hit_dn;
Debug log (debug_client 20/debug_ms 1)
2021-03-21T05:29:10.942-0700 7fccff7fe700 15 inode.put on 0x7fcd5ed3c000 0x50006cc83ae.head now 4
2021-03-21T05:29:10.942-0700 7fcd85ffb700 3 client.96500661 ll_lookup 0x50001348ff1.head .dw_gem2_cmn_sd_COMPLETE
2021-03-21T05:29:10.942-0700 7fcd85ffb700 20 client.96500661 may_lookup 0x50001348ff1.head(faked_ino=0 ref=3 ll_ref=498 cap_refs={} open={} mode=40755 size=0/0 nlink=1 btime=2019-09-24T15:45:53.816441-0700 mtime=2021-03-21T05:18:47.362286-0700 ctime=2021-03-21T05:18:47.362286-0700 caps=pAsLsXsFs(4=pAsLsXsFs) COMPLETE parents=0x4000047674c.head[".lock"] 0x7fcc7ada61f0); UserPerm(uid: 0, gid: 0)
2021-03-21T05:29:10.942-0700 7fcd85ffb700 10 client.96500661 _getattr mask As issued=1
2021-03-21T05:29:10.942-0700 7fcd85ffb700 3 client.96500661 may_lookup 0x7fcc7ada61f0 = 0
2021-03-21T05:29:10.942-0700 7fcd85ffb700 20 client.96500661 _lookup have dn .dw_gem2_cmn_sd_COMPLETE mds.-1 ttl 0.000000 seq 0
2021-03-21T05:29:10.942-0700 7fcd85ffb700 15 inode.get on 0x7fccc2606910 0x50002f121d3.head now 4
2021-03-21T05:29:10.942-0700 7fcd85ffb700 10 client.96500661 _lookup 0x50001348ff1.head(faked_ino=0 ref=3 ll_ref=498 cap_refs={} open={} mode=40755 size=0/0 nlink=1 btime=2019-09-24T15:45:53.816441-0700 mtime=2021-03-21T05:18:47.362286-0700 ctime=2021-03-21T05:18:47.362286-0700 caps=pAsLsXsFs(4=pAsLsXsFs) COMPLETE parents=0x4000047674c.head[".lock"] 0x7fcc7ada61f0) .dw_gem2_cmn_sd_COMPLETE = 0x50002f121d3.head(faked_ino=0 ref=4 ll_ref=15 cap_refs={4=0,1024=0,4096=0,8192=0} open={2=0} mode=100644 size=163/0 nlink=1 btime=2020-03-31T20:44:17.111315-0700 mtime=2021-03-21T05:18:47.373138-0700 ctime=2021-03-21T05:18:47.373138-0700 caps=pAsLsXsFscr(4=pAsLsXsFscr) objectset[0x50002f121d3 ts 6858/0 objects 1 dirty_or_tx 0] parents=0x50001348ff1.head[".dw_gem2_cmn_sd_COMPLETE"], 0x50001348ff1.head[".dw_gem2_cmn_sd_INPROGRESS"] 0x7fccc2606910)
2021-03-21T05:29:10.942-0700 7fcd85ffb700 10 client.96500661 fill_stat on 0x50002f121d3 snap/devhead mode 0100644 mtime 2021-03-21T05:18:47.373138-0700 ctime 2021-03-21T05:18:47.373138-0700
2021-03-21T05:29:10.942-0700 7fcd85ffb700 20 client.96500661 _ll_get 0x7fccc2606910 0x50002f121d3 -> 16
2021-03-21T05:29:10.942-0700 7fcd85ffb700 3 client.96500661 ll_lookup 0x50001348ff1.head .dw_gem2_cmn_sd_COMPLETE -> 0 (50002f121d3)
dump inode from mds.
root@mds:/var/run/ceph# ceph daemon /var/run/ceph/mds.asok dump inode 0x50002f121d3
{
"path": "/sharefs_prod/etl/watch/dat/hd10/dw_gem2/.lock/.dw_gem2_cmn_sd_INPROGRESS",
"ino": 5497607496147,
"rdev": 0,
"ctime": "2021-03-21T05:18:47.373138-0700",
"btime": "2020-03-31T20:44:17.111315-0700",
"mode": 33188,
"uid": 506,
"gid": 21,
"nlink": 1,
"dir_layout": {
"dir_hash": 0,
"unused1": 0,
"unused2": 0,
"unused3": 0
},
"layout": {
"stripe_unit": 4194304,
"stripe_count": 1,
"object_size": 4194304,
"pool_id": 7,
"pool_ns": ""
},
"old_pools": [
2
],
"size": 163,
"truncate_seq": 6858,
"truncate_size": 0,
"truncate_from": 0,
"truncate_pending": 0,
"mtime": "2021-03-21T05:18:47.373138-0700",
"atime": "2020-03-31T20:44:17.108239-0700",
"time_warp_seq": 1,
"change_attr": 27434,
"export_pin": -1,
"export_ephemeral_random_pin": 0,
"export_ephemeral_distributed_pin": false,
"client_ranges": [],
"dirstat": {
"version": 0,
"mtime": "0.000000",
"num_files": 0,
"num_subdirs": 0,
"change_attr": 0
},
"rstat": {
"version": 0,
"rbytes": 163,
"rfiles": 1,
"rsubdirs": 0,
"rsnaps": 0,
"rctime": "2021-03-21T05:18:47.373138-0700"
},
"accounted_rstat": {
"version": 0,
"rbytes": 163,
"rfiles": 1,
"rsubdirs": 0,
"rsnaps": 0,
"rctime": "2021-03-21T05:18:47.373138-0700"
},
"version": 193545,
"file_data_version": 0,
"xattr_version": 1,
"backtrace_version": 193538,
"stray_prior_path": "",
"max_size_ever": 173,
"quota": {
"max_bytes": 0,
"max_files": 0
},
"last_scrub_stamp": "0.000000",
"last_scrub_version": 0,
"symlink": "",
"xattrs": [],
"dirfragtree": {
"splits": []
},
"old_inodes": [],
"oldest_snap": 18446744073709551614,
"damage_flags": 0,
"is_auth": true,
"auth_state": {
"replicas": {}
},
"replica_state": {
"authority": [
4,
-2
],
"replica_nonce": 0
},
"auth_pins": 0,
"is_frozen": false,
"is_freezing": false,
"pins": {
"ptrwaiter": 0,
"request": 0,
"lock": 0,
"caps": 1,
"truncating": 0,
"dirtyrstat": 0,
"dirtyparent": 1,
"dirty": 1,
"waiter": 0,
"authpin": 0
},
"nref": 3,
"versionlock": {
"gather_set": [],
"state": "lock",
"is_leased": false,
"num_rdlocks": 0,
"num_wrlocks": 0,
"num_xlocks": 0,
"xlock_by": {}
},
"authlock": {},
"linklock": {},
"dirfragtreelock": {},
"filelock": {},
"xattrlock": {},
"snaplock": {},
"nestlock": {
"gather_set": [],
"state": "lock",
"is_leased": false,
"num_rdlocks": 0,
"num_wrlocks": 0,
"num_xlocks": 0,
"xlock_by": {}
},
"flocklock": {},
"policylock": {},
"states": [
"auth",
"dirty",
"dirtyparent"
],
"client_caps": [
{
"client_id": 96500661,
"pending": "pAsLsXsFscr",
"issued": "pAsLsXsFscr",
"wanted": "-",
"last_sent": 151
}
],
"loner": -1,
"want_loner": -1,
"mds_caps_wanted": []
}
Actions