Bug 1470599 - log messages appear stating mdkir failed on the new brick while adding brick to increase replica count.
log messages appear stating mdkir failed on the new brick while adding brick ...
Status: VERIFIED
Product: Red Hat Gluster Storage
Classification: Red Hat
Component: posix (Show other bugs)
3.2
All Linux
high Severity medium
: ---
: RHGS 3.4.0
Assigned To: Pranith Kumar K
Rahul Hinduja
rebase
:
Depends On: 1473636 1488168 1492010
Blocks: 1503134
  Show dependency treegraph
 
Reported: 2017-07-13 05:43 EDT by Karan Sandha
Modified: 2018-05-23 08:58 EDT (History)
11 users (show)

See Also:
Fixed In Version: glusterfs-3.12.2-1
Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed:
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)

  None (edit)
Description Karan Sandha 2017-07-13 05:43:16 EDT
Description of problem:
While adding an arbiter brick to volume arbiter brick has error logs for mkdir failed. 

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

How reproducible:
reported when hit

Steps to Reproduce:
1. create a replica volume.
2. run file op tool 
3. add a brick to volume 


NO I/O errors observed on the mount point.

Actual results:
errors on adding a brick to the volume
Expected results:
no errors should be observed.

Additional info:
[root@dhcp46-53 ~]# gluster v info
 
Volume Name: testvol
Type: Replicate
Volume ID: 6c4c9111-9e2d-4b00-b572-ff58bec02f77
Status: Started
Snapshot Count: 0
Number of Bricks: 1 x (2 + 1) = 3
Transport-type: tcp
Bricks:
Brick1: 10.70.46.53:/rhs/brick1/testvol
Brick2: 10.70.46.90:/rhs/brick1/testvol
Brick3: 10.70.46.227:/rhs/brick1/testvol (arbiter)
Options Reconfigured:
nfs.disable: on
performance.readdir-ahead: on
transport.address-family: inet
features.cache-invalidation: on
features.cache-invalidation-timeout: 600
performance.stat-prefetch: on
performance.cache-invalidation: on
performance.md-cache-timeout: 600
network.inode-lru-limit: 50000
server.event-threads: 8
client.event-threads: 8


===========================TESTS RUNNING===========================
Changing to the specified mountpoint
/mnt/fuse/run9126
executing fileop
start:14:10:09

real	48m16.880s
user	0m2.164s
sys	0m15.088s
end:14:58:26
1
Total 1 tests were successful
Switching over to the previous working directory
Removing /mnt/fuse//run9126/




*************ERROR in the LOGS**************
[2017-07-13 09:00:42.989301] E [MSGID: 113109] [posix.c:1539:posix_mkdir] 0-testvol-posix: mkdir (22a45e19-0c6b-4337-866c-d8666e44c334/fileop_L1_13_L2_25): getxattr on key (trusted.glusterfs.dht) path (/rhs/brick1/testvol/run9126/fileop_L1_13) failed  [No data available]
[2017-07-13 09:00:42.989350] E [MSGID: 115056] [server-rpc-fops.c:504:server_mkdir_cbk] 0-testvol-server: 321: MKDIR /run9126/fileop_L1_13/fileop_L1_13_L2_25 (22a45e19-0c6b-4337-866c-d8666e44c334/fileop_L1_13_L2_25) client: dhcp47-58.lab.eng.blr.redhat.com-8793-2017/07/13-07:34:23:506714-testvol-client-2-2-0 [No data available]
[2017-07-13 09:00:43.029195] E [inodelk.c:304:__inode_unlock_lock] 0-testvol-locks:  Matching lock not found for unlock 0-9223372036854775807, by 10c3fd393e7f0000 on 0x7fcad40f6f00
[2017-07-13 09:00:43.029240] E [MSGID: 115053] [server-rpc-fops.c:275:server_inodelk_cbk] 0-testvol-server: 364: INODELK /run9126/fileop_L1_13/fileop_L1_13_L2_25 (05193b97-19a0-4391-ac27-7aa5509a2a42) ==> (Invalid argument) [Invalid argument]


logs placed at 
rhsqe-repo.lab.eng.blr.redhat.com:/var/www/html/sosreports/<bug>
Comment 2 Nithya Balachandran 2017-07-13 05:50:57 EDT
The logs are from the brick logs where dht is not loaded. Can you please explain why you think this is a dht issue?
Comment 5 Raghavendra G 2017-07-14 00:56:00 EDT
(In reply to Nithya Balachandran from comment #2)
> The logs are from the brick logs where dht is not loaded. Can you please
> explain why you think this is a dht issue?

Its a 1x3 setup. So, I think dht is loaded. Also logs indicate that posix is looking for dht layout xattrs on parent directory which are not present causing the failure

[2017-07-13 09:00:42.989301] E [MSGID: 113109] [posix.c:1539:posix_mkdir] 0-testvol-posix: mkdir (22a45e19-0c6b-4337-866c-d8666e44c334/fileop_L1_13_L2_25): getxattr on key (trusted.glusterfs.dht) path (/rhs/brick1/testvol/run9126/fileop_L1_13) failed  [No data available]

DHT has asked for pre-op check by posix in mkdir and since layout xattrs are not present mkdir is failing.
Comment 6 Raghavendra G 2017-07-14 01:22:19 EDT
From logs, I see that mkdir has failed only on brick3 (which I assume arbiter). So, layout xattr is present on the other two bricks. Since xattr is present on 2 replica children and absent on one, assigning the bug to replicate. If you feel otherwise, please feel free to reassign back to DHT with valid reasons.
Comment 7 Ravishankar N 2017-07-14 01:36:26 EDT
Karan, I am trying to understand the criticality of this issue for rhgs.3.3. From that perspective, 

1. Can you confirm if this issue is reproducible?

2. What was the impact of this failure?
  a) Was there any failure on the mount?
  b) Did the directory in question get created on the arbiter brick (I assume not since we have failures in the posix logs)?
  c) If no, did self-heal eventually get to re-creating it as a part of entry heal?
Comment 8 Ravishankar N 2017-07-14 01:37:22 EDT
Also the bug is filed in RHGS-3.2. Is that the version you found the issue on?
Comment 9 Karan Sandha 2017-07-14 10:25:55 EDT
(In reply to Ravishankar N from comment #7)
> Karan, I am trying to understand the criticality of this issue for rhgs.3.3.
> From that perspective, 
> 
> 1. Can you confirm if this issue is reproducible?
I hit this issue once and reported it with basic *2 replica volume.
> 
> 2. What was the impact of this failure?
>   a) Was there any failure on the mount?
I found these errors on mount point logs :-
[2017-07-13 09:00:42.976907] E [MSGID: 114031] [client-rpc-fops.c:301:client3_3_mkdir_cbk] 2-testvol-client-2: remote operation failed. Path: <gfid:22a45e19-0c6b-4337-866c-d8666e44c334>/fileop_L1_13_L2_25 [No data available]
[2017-07-13 09:00:42.998375] I [MSGID: 108026] [afr-self-heal-metadata.c:52:__afr_selfheal_metadata_do] 2-testvol-replicate-0: performing metadata selfheal on 22a45e19-0c6b-4337-866c-d8666e44c334
[2017-07-13 09:00:43.008354] I [MSGID: 108026] [afr-self-heal-common.c:1212:afr_log_selfheal] 2-testvol-replicate-0: Completed metadata selfheal on 22a45e19-0c6b-4337-866c-d8666e44c334. sources=[0] 1  sinks=2 
[2017-07-13 09:00:43.016990] E [MSGID: 114031] [client-rpc-fops.c:1550:client3_3_inodelk_cbk] 2-testvol-client-2: remote operation failed [Invalid argument]

>   b) Did the directory in question get created on the arbiter brick (I
> assume not since we have failures in the posix logs)?
I saw the directory created on the mount point 
>   c) If no, did self-heal eventually get to re-creating it as a part of
> entry heal?
heal info showed no heal pending.
Comment 13 Ravishankar N 2017-07-21 07:43:43 EDT
So I was able to re-create the issue using Karan's steps. Du has already given the reason for the mkdir failed messages in comment #5. If the file is already created on the 3rd brick as a part of entry self-heal, then afr can perform a meta data heal because fuse guarantees a gfid or named lookup. See BZ 1473636 for more explanation. With the patch for that, BZ the issue is partially fixed. i.e. metadata heals now happen when the file is already present on the 3rd brick. When the file is not yet created as a part of entry self-heal, we will still see these messages.

I'm not sure at this point what to do with this BZ. Perhaps close it as can't fix. Will update once https://review.gluster.org/#/c/17850/ gets merged.

Note You need to log in before you can comment on or make changes to this bug.