Bug 1409580
| Summary: | seeing stale file handle errors in fuse mount logs in systemic testing | ||
|---|---|---|---|
| Product: | [Red Hat Storage] Red Hat Gluster Storage | Reporter: | Nag Pavan Chilakam <nchilaka> |
| Component: | distribute | Assignee: | Nithya Balachandran <nbalacha> |
| Status: | CLOSED INSUFFICIENT_DATA | QA Contact: | Sayalee <saraut> |
| Severity: | urgent | Docs Contact: | |
| Priority: | medium | ||
| Version: | rhgs-3.2 | CC: | rhs-bugs, saraut, sraut, storage-qa-internal, tdesala |
| Target Milestone: | --- | Keywords: | ZStream |
| Target Release: | --- | Flags: | tdesala:
needinfo-
|
| Hardware: | Unspecified | ||
| OS: | Unspecified | ||
| Whiteboard: | |||
| Fixed In Version: | Doc Type: | If docs needed, set a value | |
| Doc Text: | Story Points: | --- | |
| Clone Of: | Environment: | ||
| Last Closed: | 2019-10-14 08:29:10 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: | |||
other BZs for reference(raised wrt issues on same setup) 1409472 - brick crashed on systemic setup 1397907 - seeing frequent kernel hangs when doing operations both on fuse client and gluster nodes on replica volumes (edit) [NEEDINFO] 1409568 - seeing socket disconnects and transport endpoint not connected frequently on systemic setup 1409572 - In fuse mount logs:seeing input/output error with split-brain observed logs and failing GETXATTR and STAT client sosreports are available at scp -r /var/tmp/$HOSTNAME qe@rhsqe-repo:/var/www/html/sosreports/nchilaka/3.2_logs/systemic_testing_logs/regression_cycle/same_dir_create_clients/ I suspect most of these are not happening now with latest releases due to layout locking which happens. Changing the component to distribute component to re-confirm my statement, and they can close it if its fixed already. |
Description of problem: -==================== I am observing a lot of stale file handle error in my systemic testing client logs Some are saying due to unable to obtain blocking locks from afr perspective, but some are also due to different reasons as below [2016-12-31 23:21:35.182158] W [fuse-bridge.c:471:fuse_entry_cbk] 0-glusterfs-fuse: 82896290: LOOKUP() /data/same-dir-creation/level1.1/level2.1/level3.63/level4.56/level5.31 => -1 (Stale file handle) [2016-12-31 23:21:35.183005] W [MSGID: 109114] [dht-common.c:7350:dht_mkdir_guard_parent_layout_cbk] 0-sysvol-dht: mkdir (d19c0196-2ea4-4044-abe1-e71cf6a72aa5/level5.31) (path: /data/same-dir-creation/level1.1/level2.1/level3.63/level4.56/level5.31): Acquiring lock on parent to guard against layout-change failed. [Stale file handle] [2016-12-31 23:21:35.183046] W [fuse-bridge.c:471:fuse_entry_cbk] 0-glusterfs-fuse: 82896291: MKDIR() /data/same-dir-creation/level1.1/level2.1/level3.63/level4.56/level5.31 => -1 (Stale file handle) [2016-12-31 23:21:35.299954] W [fuse-bridge.c:471:fuse_entry_cbk] 0-glusterfs-fuse: 82896438: LOOKUP() /data/same-dir-creation/level1.1/level2.1/level3.63/level4.56/level5.32 => -1 (Stale file handle) [2016-12-31 23:21:35.300673] W [MSGID: 109114] [dht-common.c:7350:dht_mkdir_guard_parent_layout_cbk] 0-sysvol-dht: mkdir (d19c0196-2ea4-4044-abe1-e71cf6a72aa5/level5.32) (path: /data/same-dir-creation/level1.1/level2.1/level3.63/level4.56/level5.32): Acquiring lock on parent to guard against layout-change failed. [Stale file handle] [2016-12-31 23:21:35.300703] W [fuse-bridge.c:471:fuse_entry_cbk] 0-glusterfs-fuse: 82896439: MKDIR() /data/same-dir-creation/level1.1/level2.1/level3.63/level4.56/level5.32 => -1 (Stale file handle) [2016-12-31 23:22:00.891167] W [fuse-bridge.c:471:fuse_entry_cbk] 0-glusterfs-fuse: 82897865: LOOKUP() /data/same-dir-creation/level1.1/level2.1/level3.63/level4.56/level5.42 => -1 (Stale file handle) [2016-12-31 23:22:00.892250] W [MSGID: 109114] [dht-common.c:7350:dht_mkdir_guard_parent_layout_cbk] 0-sysvol-dht: mkdir (d19c0196-2ea4-4044-abe1-e71cf6a72aa5/level5.42) (path: /data/same-dir-creation/level1.1/level2.1/level3.63/level4.56/level5.42): Acquiring lock on parent to guard against layout-change failed. [Stale file handle] [2016-12-31 23:22:00.892289] W [fuse-bridge.c:471:fuse_entry_cbk] 0-glusterfs-fuse: 82897866: MKDIR() /data/same-dir-creation/level1.1/level2.1/level3.63/level4.56/level5.42 => -1 (Stale file handle) [2016-12-31 23:22:03.064295] W [MSGID: 108019] [afr-lk-common.c:1064:afr_log_entry_locks_failure] 0-sysvol-replicate-3: Unable to obtain sufficient blocking entry locks on at least one child while attempting MKDIR on {pgfid:d19c0196-2ea4-4044-abe1-e71cf6a72aa5, name:level5.43}. [2016-12-31 23:22:03.064322] I [MSGID: 108019] [afr-transaction.c:1870:afr_post_blocking_entrylk_cbk] 0-sysvol-replicate-3: Blocking entrylks failed. [2016-12-31 23:22:04.077308] E [MSGID: 108008] [afr-transaction.c:2602:afr_write_txn_refresh_done] 0-sysvol-replicate-3: Failing SETXATTR on gfid c1efb24c-02c3-4ee2-bea4-3d31554c90cf: split-brain observed. [2016-12-31 23:22:04.336733] W [MSGID: 108019] [afr-lk-common.c:1064:afr_log_entry_locks_failure] 0-sysvol-replicate-3: Unable to obtain sufficient blocking entry locks on at least one child while attempting MKDIR on {pgfid:d19c0196-2ea4-4044-abe1-e71cf6a72aa5, name:level5.44}. [2016-12-31 23:22:04.336766] I [MSGID: 108019] [afr-transaction.c:1870:afr_post_blocking_entrylk_cbk] 0-sysvol-replicate-3: Blocking entrylks failed. [2016-12-31 23:22:05.187297] E [MSGID: 108008] [afr-transaction.c:2602:afr_write_txn_refresh_done] 0-sysvol-replicate-3: Failing SETXATTR on gfid c3dc9895-fc94-4933-b485-6e3df042f7b1: split-brain observed. [2016-12-31 23:22:06.230478] W [MSGID: 108019] [afr-lk-common.c:1064:afr_log_entry_locks_failure] 0-sysvol-replicate-3: Unable to obtain sufficient blocking entry locks on at least one child while attempting MKDIR on {pgfid:d19c0196-2ea4-4044-abe1-e71cf6a72aa5, name:level5.45}. [2016-12-31 23:22:06.230510] I [MSGID: 108019] [afr-transaction.c:1870:afr_post_blocking_entrylk_cbk] 0-sysvol-replicate-3: Blocking entrylks failed. [2016-12-31 23:22:06.615298] E [MSGID: 108008] [afr-transaction.c:2602:afr_write_txn_refresh_done] 0-sysvol-replicate-3: Failing SETXATTR on gfid 533a1399-3753-4070-9c7f-5cf1e0da21ca: split-brain observed. [2016-12-31 23:22:07.892288] W [fuse-bridge.c:471:fuse_entry_cbk] 0-glusterfs-fuse: 82898430: LOOKUP() /data/same-dir-creation/level1.1/level2.1/level3.63/level4.56/level5.46 => -1 (Stale file handle) [2016-12-31 23:22:07.893839] W [MSGID: 109114] [dht-common.c:7350:dht_mkdir_guard_parent_layout_cbk] 0-sysvol-dht: mkdir (d19c0196-2ea4-4044-abe1-e71cf6a72aa5/level5.46) (path: /data/same-dir-creation/level1.1/level2.1/level3.63/level4.56/level5.46): Acquiring lock on parent to guard against layout-change failed. [Stale file handle] [2016-12-31 23:22:07.893878] W [fuse-bridge.c:471:fuse_entry_cbk] 0-glusterfs-fuse: 82898431: MKDIR() /data/same-dir-creation/level1.1/level2.1/level3.63/level4.56/level5.46 => -1 (Stale file handle) [2016-12-31 23:22:08.464591] W [MSGID: 108019] [afr-lk-common.c:1064:afr_log_entry_locks_failure] 0-sysvol-replicate-3: Unable to obtain sufficient blocking entry locks on at least one child while attempting MKDIR on {pgfid:d19c0196-2ea4-4044-abe1-e71cf6a72aa5, name:level5.47}. [2016-12-31 23:22:08.464617] I [MSGID: 108019] [afr-transaction.c:1870:afr_post_blocking_entrylk_cbk] 0-sysvol-replicate-3: Blocking entrylks failed. [2016-12-31 23:22:08.718294] E [MSGID: 108008] [afr-transaction.c:2602:afr_write_txn_refresh_done] 0-sysvol-replicate-3: Failing SETXATTR on gfid f4bf83a7-5059-4885-a57c-7b5ae5abe4f6: split-brain observed. [2016-12-31 23:22:10.451499] W [MSGID: 108019] [afr-lk-common.c:1064:afr_log_entry_locks_failure] 0-sysvol-replicate-3: Unable to obtain sufficient blocking entry locks on at least one child while attempting MKDIR on {pgfid:d19c0196-2ea4-4044-abe1-e71cf6a72aa5, name:level5.48}. [2016-12-31 23:22:10.451533] I [MSGID: 108019] [afr-transaction.c:1870:afr_post_blocking_entrylk_cbk] 0-sysvol-replicate-3: Blocking entrylks failed. [2016-12-31 23:22:10.578723] E [MSGID: 108008] [afr-transaction.c:2602:afr_write_txn_refresh_done] 0-sysvol-replicate-3: Failing SETXATTR on gfid edcaa496-457c-4b96-8069-653f791c7bb6: split-brain observed. [2016-12-31 23:22:11.335650] W [MSGID: 108019] [afr-lk-common.c:1064:afr_log_entry_locks_failure] 0-sysvol-replicate-3: Unable to obtain sufficient blocking entry locks on at least one child while attempting MKDIR on {pgfid:d19c0196-2ea4-4044-abe1-e71cf6a72aa5, name:level5.49}. [2016-12-31 23:22:11.335676] I [MSGID: 108019] [afr-transaction.c:1870:afr_post_blocking_entrylk_cbk] 0-sysvol-replicate-3: Blocking entrylks failed. [2016-12-31 23:22:11.343906] E [MSGID: 108008] [afr-transaction.c:2602:afr_write_txn_refresh_done] 0-sysvol-replicate-3: Failing SETXATTR on gfid 635097ab-3f53-42be-bde8-a68f67e59743: split-brain observed. [2016-12-31 23:22:11.488969] W [fuse-bridge.c:471:fuse_entry_cbk] 0-glusterfs-fuse: 82898988: LOOKUP() /data/same-dir-creation/level1.1/level2.1/level3.63/level4.56/level5.50 => -1 (Stale file handle) : [2016-12-31 23:23:54.524857] W [MSGID: 108019] [afr-lk-common.c:1064:afr_log_entry_locks_failure] 0-sysvol-replicate-3: Unable to obtain sufficient blocking entry locks on at least one child while attempting MKDIR on {pgfid:d19c0196-2ea4-4044-abe1-e71cf6a72aa5, name:level5.55}. [2016-12-31 23:23:54.524906] I [MSGID: 108019] [afr-transaction.c:1870:afr_post_blocking_entrylk_cbk] 0-sysvol-replicate-3: Blocking entrylks failed. [2016-12-31 23:24:02.777136] E [MSGID: 108008] [afr-transaction.c:2602:afr_write_txn_refresh_done] 0-sysvol-replicate-3: Failing SETXATTR on gfid a0484168-44df-4354-b5ff -520f14e9fd9d: split-brain observed. [2016-12-31 23:24:06.397096] W [fuse-bridge.c:471:fuse_entry_cbk] 0-glusterfs-fuse: 82903022: LOOKUP() /data/same-dir-creation/level1.1/level2.1/level3.63/level4.56/leve l5.56 => -1 (Stale file handle) [2016-12-31 23:24:06.399300] W [MSGID: 109114] [dht-common.c:7350:dht_mkdir_guard_parent_layout_cbk] 0-sysvol-dht: mkdir (d19c0196-2ea4-4044-abe1-e71cf6a72aa5/level5.56) (path: /data/same-dir-creation/level1.1/level2.1/level3.63/level4.56/level5.56): Acquiring lock on parent to guard against layout-change failed. [Stale file handle] [2016-12-31 23:24:06.399339] W [fuse-bridge.c:471:fuse_entry_cbk] 0-glusterfs-fuse: 82903023: MKDIR() /data/same-dir-creation/level1.1/level2.1/level3.63/level4.56/level 5.56 => -1 (Stale file handle) [2016-12-31 23:24:12.333705] W [fuse-bridge.c:471:fuse_entry_cbk] 0-glusterfs-fuse: 82903173: LOOKUP() /data/same-dir-creation/level1.1/level2.1/level3.63/level4.56/level5.57 => -1 (Stale file handle) [2016-12-31 23:24:12.354911] W [MSGID: 109114] [dht-common.c:7350:dht_mkdir_guard_parent_layout_cbk] 0-sysvol-dht: mkdir (d19c0196-2ea4-4044-abe1-e71cf6a72aa5/level5.57) (path: /data/same-dir-creation/level1.1/level2.1/level3.63/level4.56/level5.57): Acquiring lock on parent to guard against layout-change failed. [Stale file handle] [2016-12-31 23:24:12.354961] W [fuse-bridge.c:471:fuse_entry_cbk] 0-glusterfs-fuse: 82903174: MKDIR() /data/same-dir-creation/level1.1/level2.1/level3.63/level4.56/level5.57 => -1 (Stale file handle) [2016-12-31 23:24:15.718800] W [fuse-bridge.c:471:fuse_entry_cbk] 0-glusterfs-fuse: 82903319: LOOKUP() /data/same-dir-creation/level1.1/level2.1/level3.63/level4.56/level5.58 => -1 (Stale file handle) [2016-12-31 23:24:15.735609] W [MSGID: 109114] [dht-common.c:7350:dht_mkdir_guard_parent_layout_cbk] 0-sysvol-dht: mkdir (d19c0196-2ea4-4044-abe1-e71cf6a72aa5/level5.58) (path: /data/same-dir-creation/level1.1/level2.1/level3.63/level4.56/level5.58): Acquiring lock on parent to guard against layout-change failed. [Stale file handle] [2016-12-31 23:24:15.735662] W [fuse-bridge.c:471:fuse_entry_cbk] 0-glusterfs-fuse: 82903320: MKDIR() /data/same-dir-creation/level1.1/level2.1/level3.63/level4.56/level5.58 => -1 (Stale file handle) [2016-12-31 23:24:16.950286] W [MSGID: 108019] [afr-lk-common.c:1064:afr_log_entry_locks_failure] 0-sysvol-replicate-3: Unable to obtain sufficient blocking entry locks on at least one child while attempting MKDIR on {pgfid:d19c0196-2ea4-4044-abe1-e71cf6a72aa5, name:level5.59}. [2017-01-01 00:11:06.798004] E [MSGID: 108008] [afr-transaction.c:2602:afr_write_txn_refresh_done] 0-sysvol-replicate-1: Failing SETXATTR on gfid 3450ab56-fe28-4c17-9f30-afc0ecf9d164: split-brain observed. [2017-01-01 00:11:07.086220] W [fuse-bridge.c:471:fuse_entry_cbk] 0-glusterfs-fuse: 82997083: LOOKUP() /data/same-dir-creation/level1.1/level2.1/level3.63/level4.71/level5.53 => -1 (Stale file handle) [2017-01-01 00:11:07.087583] W [MSGID: 109114] [dht-common.c:7350:dht_mkdir_guard_parent_layout_cbk] 0-sysvol-dht: mkdir (f63e9f80-ab53-42ef-ab64-623618c4274c/level5.53) (path: /data/same-dir-creation/level1.1/level2.1/level3.63/level4.71/level5.53): Acquiring lock on parent to guard against layout-change failed. [Stale file handle] [2017-01-01 00:11:07.087631] W [fuse-bridge.c:471:fuse_entry_cbk] 0-glusterfs-fuse: 82997084: MKDIR() /data/same-dir-creation/level1.1/level2.1/level3.63/level4.71/level5.53 => -1 (Stale file handle) [2017-01-01 00:11:20.338332] W [fuse-bridge.c:471:fuse_entry_cbk] 0-glusterfs-fuse: 82997227: LOOKUP() /data/same-dir-creation/level1.1/level2.1/level3.63/level4.71/level5.54 => -1 (Stale file handle) [2017-01-01 00:11:20.339801] W [MSGID: 109114] [dht-common.c:7350:dht_mkdir_guard_parent_layout_cbk] 0-sysvol-dht: mkdir (f63e9f80-ab53-42ef-ab64-623618c4274c/level5.54) (path: /data/same-dir-creation/level1.1/level2.1/level3.63/level4.71/level5.54): Acquiring lock on parent to guard against layout-change failed. [Stale file handle] [2017-01-01 00:11:20.339840] W [fuse-bridge.c:471:fuse_entry_cbk] 0-glusterfs-fuse: 82997228: MKDIR() /data/same-dir-creation/level1.1/level2.1/level3.63/level4.71/level5.54 => -1 (Stale file handle) [2017-01-01 00:11:20.560877] W [fuse-bridge.c:471:fuse_entry_cbk] 0-glusterfs-fuse: 82997364: LOOKUP() /data/same-dir-creation/level1.1/level2.1/level3.63/level4.71/level5.55 => -1 (Stale file handle) [2017-01-01 00:11:20.562207] W [MSGID: 109114] [dht-common.c:7350:dht_mkdir_guard_parent_layout_cbk] 0-sysvol-dht: mkdir (f63e9f80-ab53-42ef-ab64-623618c4274c/level5.55) (path: /data/same-dir-creation/level1.1/level2.1/level3.63/level4.71/level5.55): Acquiring lock on parent to guard against layout-change failed. [Stale file handle] [2017-01-01 00:11:20.562240] W [fuse-bridge.c:471:fuse_entry_cbk] 0-glusterfs-fuse: 82997365: MKDIR() /data/same-dir-creation/level1.1/level2.1/level3.63/level4.71/level5.55 => -1 (Stale file handle) [2017-01-01 00:11:22.120169] W [MSGID: 108019] [afr-lk-common.c:1064:afr_log_entry_locks_failure] 0-sysvol-replicate-1: Unable to obtain sufficient blocking entry locks on at least one child while attempting MKDIR on {pgfid:f63e9f80-ab53-42ef-ab64-623618c4274c, name:level5.56}. [2017-01-01 01:42:56.288385] I [MSGID: 109063] [dht-layout.c:713:dht_layout_normalize] 0-sysvol-dht: Found anomalies in /data/same-dir-creation/level1.1/level2.1/level3.63/level4.82/level5.77 (gfid = d039bb11-d902-4487-ba6e-206122e73030). Holes=1 overlaps=0 [2017-01-01 01:42:59.445845] W [fuse-bridge.c:471:fuse_entry_cbk] 0-glusterfs-fuse: 83189811: LOOKUP() /data/same-dir-creation/level1.1/level2.1/level3.63/level4.82/level5.77 => -1 (Stale file handle) [2017-01-01 01:42:59.499076] W [fuse-resolve.c:61:fuse_resolve_entry_cbk] 0-fuse: f978e84a-6daa-4901-9398-399949167bec/level5.77: failed to resolve (Stale file handle) [2017-01-01 01:42:59.505583] W [fuse-bridge.c:471:fuse_entry_cbk] 0-glusterfs-fuse: 83189813: MKDIR() /data/same-dir-creation/level1.1/level2.1/level3.63/level4.82/level5.77 => -1 (File exists) [2017-01-01 01:43:00.592121] W [fuse-resolve.c:61:fuse_resolve_entry_cbk] 0-fuse: f978e84a-6daa-4901-9398-399949167bec/level5.77: failed to resolve (Stale file handle) [2017-01-01 01:43:03.304138] W [fuse-bridge.c:471:fuse_entry_cbk] 0-glusterfs-fuse: 83189814: LOOKUP() /data/same-dir-creation/level1.1/level2.1/level3.63/level4.82/level5.77 => -1 (Stale file handle) The message "I [MSGID: 109063] [dht-layout.c:713:dht_layout_normalize] 0-sysvol-dht: Found anomalies in /data/same-dir-creation/level1.1/level2.1/level3.63/level4.82/level5.77 (gfid = d039bb11-d902-4487-ba6e-206122e73030). Holes=1 overlaps=0" repeated 3 times between [2017-01-01 01:42:56.288385] and [2017-01-01 01:43:00.598332] [2017-01-01 01:43:09.385817] I [MSGID: 114057] [client-handshake.c:1446:select_server_supported_programs] 0-sysvol-client-7: Using Program GlusterFS 3.3, Num (1298437), Version (330) [2017-01-01 16:55:53.834474] W [fuse-bridge.c:471:fuse_entry_cbk] 0-glusterfs-fuse: 84415960: LOOKUP() /data/same-dir-creation/level1.1/level2.1/level3.64/level4.72/level5.36 => -1 (Stale file handle) [2017-01-01 16:55:55.359411] W [MSGID: 109011] [dht-layout.c:186:dht_layout_search] 0-sysvol-dht: no subvolume for hash (value) = 2971697818 [2017-01-01 16:55:55.361891] W [fuse-bridge.c:471:fuse_entry_cbk] 0-glusterfs-fuse: 84416100: LOOKUP() /data/same-dir-creation/level1.1/level2.1/level3.64/level4.72/level5.37 => -1 (Stale file handle) [2017-01-01 16:55:55.362255] W [fuse-bridge.c:471:fuse_entry_cbk] 0-glusterfs-fuse: 84416101: MKDIR() /data/same-dir-creation/level1.1/level2.1/level3.64/level4.72/level5.37 => -1 (Input/output error) [2017-01-01 16:55:55.363642] W [fuse-bridge.c:471:fuse_entry_cbk] 0-glusterfs-fuse: 84416102: LOOKUP() /data/same-dir-creation/level1.1/level2.1/level3.64/level4.72/level5.37 => -1 (Stale file handle) The message "W [MSGID: 109011] [dht-layout.c:186:dht_layout_search] 0-sysvol-dht: no subvolume for hash (value) = 2971697818" repeated 2 times between [2017-01-01 16:55:55.359411] and [2017-01-01 16:55:55.362405] [2017-01-01 16:55:55.477048] W [MSGID: 109011] [dht-layout.c:186:dht_layout_search] 0-sysvol-dht: no subvolume for hash (value) = 2170879200 [2017-01-01 16:55:55.478682] W [fuse-bridge.c:471:fuse_entry_cbk] 0-glusterfs-fuse: 84416253: LOOKUP() /data/same-dir-creation/level1.1/level2.1/level3.64/level4.72/level5.38 => -1 (Stale file handle) On my systemic setup, I am doing same path directory creation simultaneously from 3 different clients. Each client used different server IP to mount the volume using fuse protocol Also, Each client were dumping sosreports every 5min into the volume mount in a screen session, along with top output being appended to a file every minute The dir-creations were happening from different users Eg: client1(el 7.2) was running the dir-creation using pavan@rhs-client23 client2(el 6.7) as root@rhs-client24 client3(el 7.3) as cli21@rhs-client21 Note: these logs are wrt client1 ie rhs-client23 Also, however note that I am able to access the mount sosreports available at http://rhsqe-repo.lab.eng.blr.redhat.com/sosreports/nchilaka/3.2_logs/systemic_testing_logs/regression_cycle/same_dir_create_clients/rhs-client23.lab.eng.blr.redhat.com/ test execution details available at https://docs.google.com/spreadsheets/d/1iP5Mi1TewBFVh8HTmlcBm9072Bgsbgkr3CLcGmawDys/edit#gid=632186609 Version-Release number of selected component (if applicable): ============ 3.8.4-10