Bug 763835 (GLUSTER-2103) - [3.1.1qa5]: Incomplete self-heal
Summary: [3.1.1qa5]: Incomplete self-heal
Keywords:
Status: CLOSED WORKSFORME
Alias: GLUSTER-2103
Product: GlusterFS
Classification: Community
Component: replicate
Version: 3.1.1
Hardware: All
OS: Linux
low
low
Target Milestone: ---
Assignee: Pranith Kumar K
QA Contact:
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2010-11-13 00:28 UTC by Harshavardhana
Modified: 2015-03-23 01:04 UTC (History)
3 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed:
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Embargoed:


Attachments (Terms of Use)

Description Harshavardhana 2010-11-12 21:30:16 UTC
After removing the bigfile from compel2 backend "/sdb" and triggered the self-heal it worked perfectly fine. 

Since i did shutdown the node compel2 when the dd was going on, looks like the bigfile on "/sdb" was in inconsistent state and was not self-healed properly with the copy @ "/sdc" on compel3.

Comment 1 Harshavardhana 2010-11-13 00:28:03 UTC
[root@compel3 sdc]# gluster volume info 

Volume Name: repl
Type: Replicate
Status: Started
Number of Bricks: 2
Transport-type: tcp
Bricks:
Brick1: 10.1.10.112:/sdb
Brick2: 10.1.10.113:/sdc

---- Relevant logs ---- 

[2010-11-12 16:18:10.903334] I [afr-common.c:613:afr_lookup_self_heal_check] repl-replicate-0: size differs for /bigfile 
[2010-11-12 16:18:10.903382] I [afr-common.c:716:afr_lookup_done] repl-replicate-0: background  data self-heal triggered. path: /bigfile
[2010-11-12 16:18:11.250823] I [afr-common.c:613:afr_lookup_self_heal_check] repl-replicate-0: size differs for /bigfile 
[2010-11-12 16:18:11.296244] I [afr-common.c:613:afr_lookup_self_heal_check] repl-replicate-0: size differs for /bigfile 
[2010-11-12 16:18:16.480852] I [afr-self-heal-algorithm.c:976:sh_diff_loop_driver] repl-replicate-0: diff  data self-heal on /bigfile: 0 blocks of 2378 were different (0.00%)
[2010-11-12 16:18:16.482219] I [afr-self-heal-common.c:1526:afr_self_heal_completion_cbk] repl-replicate-0: background  data self-heal completed on /bigfile



[root@compel3 sdc]# du -sh /sdc/bigfile 
298M    /sdc/bigfile

[root@compel3 sdc]# getfattr -d -m. -e hex bigfile 
# file: bigfile
trusted.afr.repl-client-0=0x000000000000000000000000
trusted.afr.repl-client-1=0x000000000000000000000000
trusted.gfid=0x872de56eef4349babee5744140fb2bd1

[root@compel3 sdc]# stat bigfile 
  File: `bigfile'
  Size: 311674880       Blocks: 609360     IO Block: 4096   regular file
Device: 820h/2080d      Inode: 49153       Links: 1
Access: (0644/-rw-r--r--)  Uid: (    0/    root)   Gid: (    0/    root)
Access: 1969-12-31 16:00:00.000000000 -0800
Modify: 2010-11-12 16:15:50.000000000 -0800
Change: 2010-11-12 16:18:16.000000000 -0800


[root@compel2 sdb]# du -sh bigfile 
52M     bigfile

[root@compel2 sdb]# getfattr -d -m. -e hex bigfile 
# file: bigfile
trusted.afr.repl-client-0=0x000000000000000000000000
trusted.afr.repl-client-1=0x000000000000000000000000
trusted.gfid=0x872de56eef4349babee5744140fb2bd1

[root@compel2 sdb]# stat bigfile 
  File: `bigfile'
  Size: 311674880       Blocks: 106168     IO Block: 4096   regular file
Device: 810h/2064d      Inode: 49153       Links: 1
Access: (0644/-rw-r--r--)  Uid: (    0/    root)   Gid: (    0/    root)
Access: 1969-12-31 16:00:00.000000000 -0800
Modify: 2010-11-12 16:15:50.000000000 -0800
Change: 2010-11-12 16:19:01.000000000 -0800


---- stat from glusterfs native ---- 

[root@compel3 sdc]# stat /share/bigfile 
  File: `/share/bigfile'
  Size: 311674880       Blocks: 609360     IO Block: 4096   regular file
Device: 18h/24d Inode: 98306       Links: 1
Access: (0644/-rw-r--r--)  Uid: (    0/    root)   Gid: (    0/    root)
Access: 1969-12-31 16:00:00.000000000 -0800
Modify: 2010-11-12 16:15:50.000000000 -0800
Change: 2010-11-12 16:18:16.000000000 -0800

[root@compel2 sdb]# stat /share/bigfile 
  File: `/share/bigfile'
  Size: 311674880       Blocks: 106168     IO Block: 4096   regular file
Device: 18h/24d Inode: 98306       Links: 1
Access: (0644/-rw-r--r--)  Uid: (    0/    root)   Gid: (    0/    root)
Access: 1969-12-31 16:00:00.000000000 -0800
Modify: 2010-11-12 16:15:50.000000000 -0800
Change: 2010-11-12 16:19:01.000000000 -0800


What is worrying here is that replicate says self-heal is completed which it isn't from the file size. I have triggered self-heal as soon as the volume was up. Note there was no background self-heal going on, file size has remained stagnant at 52MB.

Comment 2 Pranith Kumar K 2011-01-24 05:47:35 UTC
(In reply to comment #1)
> After removing the bigfile from compel2 backend "/sdb" and triggered the
> self-heal it worked perfectly fine. 
> 
> Since i did shutdown the node compel2 when the dd was going on, looks like the
> bigfile on "/sdb" was in inconsistent state and was not self-healed properly
> with the copy @ "/sdc" on compel3.

I tried reproducing this bug as a non-root user, then it gave the same error like in the logs, but with the fix of BUG 2296 The self-heal happened.

could you confirm if you did these operations as non-root-user.

here are the logs:
[2011-01-24 14:01:01.724057] I [client-handshake.c:1005:select_server_supported_programs] vol1-client-0: Using Program GlusterFS-3.1.0, Num (1298437), Version (310)
[2011-01-24 14:01:01.724703] I [client-handshake.c:841:client_setvolume_cbk] vol1-client-0: Connected to 127.0.1.1:24009, attached to remote volume '/tmp/1'.
[2011-01-24 14:01:01.724770] I [afr-common.c:2572:afr_notify] vol1-replicate-0: Subvolume 'vol1-client-0' came back up; going online.
[2011-01-24 14:01:01.736096] I [client-handshake.c:1005:select_server_supported_programs] vol1-client-1: Using Program GlusterFS-3.1.0, Num (1298437), Version (310)
[2011-01-24 14:01:01.736308] I [fuse-bridge.c:2821:fuse_init] glusterfs-fuse: FUSE inited with protocol versions: glusterfs 7.13 kernel 7.13
[2011-01-24 14:01:01.736477] I [client-handshake.c:841:client_setvolume_cbk] vol1-client-1: Connected to 127.0.1.1:24010, attached to remote volume '/tmp/2'.
[2011-01-24 14:01:01.736893] I [afr-common.c:819:afr_fresh_lookup_cbk] vol1-replicate-0: added root inode
[2011-01-24 14:02:50.475969] I [client.c:1590:client_rpc_notify] vol1-client-0: disconnected
[2011-01-24 14:03:03.733054] E [socket.c:1661:socket_connect_finish] vol1-client-0: connection to 127.0.1.1:24009 failed (Connection refused)
[2011-01-24 14:03:51.747065] I [client-handshake.c:1005:select_server_supported_programs] vol1-client-0: Using Program GlusterFS-3.1.0, Num (1298437), Version (310)
[2011-01-24 14:03:51.754245] I [client-handshake.c:841:client_setvolume_cbk] vol1-client-0: Connected to 127.0.1.1:24009, attached to remote volume '/tmp/1'.
[2011-01-24 14:03:51.754372] I [client-handshake.c:710:client_post_handshake] vol1-client-0: 1 fds open - Delaying child_up until they are re-opened
[2011-01-24 14:03:51.755068] I [client-handshake.c:407:client3_1_reopen_cbk] vol1-client-0: reopen on /temp.txt succeeded (remote-fd = 0)
[2011-01-24 14:04:29.479051] I [afr-common.c:613:afr_lookup_self_heal_check] vol1-replicate-0: size differs for /temp.txt 
[2011-01-24 14:04:29.479216] I [afr-common.c:716:afr_lookup_done] vol1-replicate-0: background  data self-heal triggered. path: /temp.txt                                
[2011-01-24 14:04:30.980158] I [afr-common.c:613:afr_lookup_self_heal_check] vol1-replicate-0: size differs for /temp.txt 
[2011-01-24 14:04:33.63760] I [afr-common.c:613:afr_lookup_self_heal_check] vol1-replicate-0: size differs for /temp.txt 
[2011-01-24 14:04:34.770937] I [afr-common.c:613:afr_lookup_self_heal_check] vol1-replicate-0: size differs for /temp.txt 
[2011-01-24 14:04:35.721127] I [afr-self-heal-algorithm.c:976:sh_diff_loop_driver] vol1-replicate-0: diff  data self-heal on /temp.txt: 2256 blocks of 2384 were different (94.63%)
[2011-01-24 14:04:35.722081] I [afr-self-heal-common.c:1526:afr_self_heal_completion_cbk] vol1-replicate-0: background  data self-heal completed on /temp.txt

pranith @ /mnt/client
14:01:07 :) $ sudo dd if=/dev/urandom of=$PWD/temp.txt bs=1M count=298

298+0 records in
298+0 records out
312475648 bytes (312 MB) copied, 51.2829 s, 6.1 MB/s

pranith @ /mnt/client
14:03:38 :) $ ls -l
total 16408
-rw-r--r-- 1 root root 16777216 2011-01-24 14:02 temp.txt

pranith @ /mnt/client
14:04:07 :) $ ls -lh /tmp/1
total 17M
-rw-r--r-- 1 root root 16M 2011-01-24 14:02 temp.txt

pranith @ /mnt/client
14:04:14 :) $ ls -lh /tmp/2
total 299M
-rw-r--r-- 1 root root 298M 2011-01-24 14:03 temp.txt

pranith @ /mnt/client
14:04:15 :) $ ls -lh temp.txt 
-rw-r--r-- 1 root root 298M 2011-01-24 14:03 temp.txt

pranith @ /mnt/client
14:04:30 :) $ ls -lh temp.txt 
-rw-r--r-- 1 root root 298M 2011-01-24 14:03 temp.txt

pranith @ /mnt/client
14:04:33 :) $ ls -lh temp.txt 
-rw-r--r-- 1 root root 298M 2011-01-24 14:03 temp.txt

Comment 3 Harshavardhana 2011-01-26 22:22:45 UTC
(In reply to comment #2)
> (In reply to comment #1)
> > After removing the bigfile from compel2 backend "/sdb" and triggered the
> > self-heal it worked perfectly fine. 
> > 
> > Since i did shutdown the node compel2 when the dd was going on, looks like the
> > bigfile on "/sdb" was in inconsistent state and was not self-healed properly
> > with the copy @ "/sdc" on compel3.
> 
> I tried reproducing this bug as a non-root user, then it gave the same error
> like in the logs, but with the fix of BUG 2296 The self-heal happened.
> 
> could you confirm if you did these operations as non-root-user.
> 
This inconsistent state was reached when a volume is taken down and brought back up. 

In above case 52MB was written on both the subvolumes in replicated pair. At that time one of them was brought down and i/o continued and completed with 292MB. Now after that we brought up the compel3 and started self-heal. But even after some time we saw that the sizes were mismatching.

Not sure if its still present in git codebase, since i don't have the bandwidth to test it. I would say if it works for you in the scenario i described above, then close this as "WORKSFORME"

Comment 4 Pranith Kumar K 2011-01-27 00:32:01 UTC
with the fix for BUG 2296 it worked fine. So marking it as WORKSFORME for now. If it re-appears please re-open it.


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