tests: improve and fix some test scripts

Change-Id: Iceefe22af754096c599dc570d4894d14fce4deae
Updates: bz#1193929
Signed-off-by: Xavier Hernandez <xhernandez@redhat.com>

18 files changed, 162 insertions, 69 deletions

diff --git a/tests/basic/afr/gfid-self-heal.t b/tests/basic/afr/gfid-self-heal.t
index b54edbcae85..5a530681186 100644
--- a/tests/basic/afr/gfid-self-heal.t
+++ b/tests/basic/afr/gfid-self-heal.t
@@ -50,6 +50,10 @@ TEST kill_brick $V0 $H0 $B0/${V0}0
 TEST touch $M0/a
 gfid_1=$(gf_get_gfid_xattr $B0/${V0}1/a)
 TEST touch $B0/${V0}0/a
+# storage/posix considers that a file without gfid changed less than a second
+# before doesn't exist, so we need to wait for a second to force posix to
+# consider that this is a valid file but without gfid.
+sleep 1
 $CLI volume start $V0 force
 EXPECT_WITHIN $PROCESS_UP_TIMEOUT "1" afr_child_up_status $V0 0
 TEST stat $M0/a
@@ -62,6 +66,10 @@ TEST kill_brick $V0 $H0 $B0/${V0}0
 TEST touch $M0/b
 TEST mkdir $B0/${V0}0/b
 TEST setfattr -x trusted.afr.$V0-client-0 $B0/${V0}1
+# storage/posix considers that a file without gfid changed less than a second
+# before doesn't exist, so we need to wait for a second to force posix to
+# consider that this is a valid file but without gfid.
+sleep 1
 $CLI volume start $V0 force
 EXPECT_WITHIN $PROCESS_UP_TIMEOUT "1" afr_child_up_status $V0 0
 TEST ! stat $M0/b
@@ -71,6 +79,10 @@ TEST "[[ -z \"$gfid_0\" ]]"
 #Check gfid assigning doesn't happen when there is type mismatch
 TEST touch $B0/${V0}1/c
 TEST mkdir $B0/${V0}0/c
+# storage/posix considers that a file without gfid changed less than a second
+# before doesn't exist, so we need to wait for a second to force posix to
+# consider that this is a valid file but without gfid.
+sleep 1
 TEST ! stat $M0/c
 gfid_1=$(gf_get_gfid_xattr $B0/${V0}1/c)
 gfid_0=$(gf_get_gfid_xattr $B0/${V0}0/c)
@@ -81,6 +93,10 @@ TEST "[[ -z \"$gfid_0\" ]]"
 # gfid split-brain
 TEST kill_brick $V0 $H0 $B0/${V0}0
 TEST touch $B0/${V0}1/d
+# storage/posix considers that a file without gfid changed less than a second
+# before doesn't exist, so we need to wait for a second to force posix to
+# consider that this is a valid file but without gfid.
+sleep 1
 TEST ! stat $M0/d
 gfid_1=$(gf_get_gfid_xattr $B0/${V0}1/d)
 TEST "[[ -z \"$gfid_1\" ]]"
diff --git a/tests/basic/afr/split-brain-heal-info.t b/tests/basic/afr/split-brain-heal-info.t
index 66275c57207..2e4742fff08 100644
--- a/tests/basic/afr/split-brain-heal-info.t
+++ b/tests/basic/afr/split-brain-heal-info.t
@@ -47,9 +47,11 @@ SPB_FILES=$(($SPB_FILES + 1))
 
 #### Simulate entry-split-brain
 TEST kill_brick $V0 $H0 $B0/${V0}0
+EXPECT_WITHIN ${PROCESS_DOWN_TIMEOUT} "^0$" afr_child_up_status $V0 0
 TEST touch $M0/espb/a
 volume_start_force $V0
 TEST kill_brick $V0 $H0 $B0/${V0}1
+EXPECT_WITHIN ${PROCESS_DOWN_TIMEOUT} "^0$" afr_child_up_status $V0 1
 TEST mkdir $M0/espb/a
 volume_start_force $V0
 SPB_FILES=$(($SPB_FILES + 1))
diff --git a/tests/basic/afr/ta-read.t b/tests/basic/afr/ta-read.t
index f2b3c38e06c..d6f9332d757 100644
--- a/tests/basic/afr/ta-read.t
+++ b/tests/basic/afr/ta-read.t
@@ -32,13 +32,17 @@ EXPECT "000000010000000000000000" get_hex_xattr trusted.afr.$V0-client-0 $B0/bri
 EXPECT "000000010000000000000000" get_hex_xattr trusted.afr.$V0-client-0 $B0/ta/trusted.afr.patchy-ta-2
 
 #Umount and mount to remove cached data.
-TEST umount $M0
+EXPECT_WITHIN $UMOUNT_TIMEOUT "Y" force_umount $M0
 TEST ta_start_mount_process $M0
 EXPECT_WITHIN $PROCESS_UP_TIMEOUT "1" ta_up_status $V0 $M0 0
 EXPECT_WITHIN $PROCESS_UP_TIMEOUT "1" afr_child_up_status_meta $M0 $V0-replicate-0 1
 # Read must be allowed since good brick is up.
 TEST  cat $M0/FILE
 
+#Umount and mount to remove cached data.
+EXPECT_WITHIN $UMOUNT_TIMEOUT "Y" force_umount $M0
+TEST ta_start_mount_process $M0
+EXPECT_WITHIN $PROCESS_UP_TIMEOUT "1" ta_up_status $V0 $M0 0
 # Toggle good and bad data brick processes.
 TEST ta_start_brick_process brick0
 EXPECT_WITHIN $PROCESS_UP_TIMEOUT "1" afr_child_up_status_meta $M0 $V0-replicate-0 0
diff --git a/tests/basic/ec/ec-1468261.t b/tests/basic/ec/ec-1468261.t
index 902fbb7d2f1..439808483e1 100644
--- a/tests/basic/ec/ec-1468261.t
+++ b/tests/basic/ec/ec-1468261.t
@@ -58,15 +58,13 @@ EXPECT_WITHIN $UMOUNT_TIMEOUT "Y" force_umount $M0
 TEST glusterfs -s $H0 --volfile-id $V0 $M0;
 
 #Create a tar file
-TEST mkdir $M0/test_dir
-for i in {1..3000};do
-dd if=/dev/urandom of=$M0/test_dir/file-$i bs=1k count=10;
-done
-tar -cf $M0/test_dir.tar $M0/test_dir/ 2>/dev/null
-rm -rf $M0/test_dir/
+TEST mkdir /tmp/test_dir
+echo /tmp/test_dir/file-{1..3000} | xargs -n 1 -P 20 -I {} dd if=/dev/urandom of={} bs=10K count=1
+tar -cf /tmp/test_dir.tar /tmp/test_dir/ 2>/dev/null
+rm -rf /tmp/test_dir/
 
 #Untar the tar file
-tar -C $M0 -xf $M0/test_dir.tar 2>/dev/null&
+tar -C $M0 -xf /tmp/test_dir.tar 2>/dev/null&
 
 #Kill 1st and 2nd brick
 TEST kill_brick $V0 $H0 $B0/${V0}0
@@ -75,6 +73,7 @@ EXPECT_WITHIN $CHILD_UP_TIMEOUT "4" ec_child_up_count $V0 0
 
 #Stop untaring
 TEST kill %1
+rm -f /tmp/test_dir.tar
 
 #Bring up the down bricks
 TEST $CLI volume start $V0 force
diff --git a/tests/basic/ec/ec-fix-openfd.t b/tests/basic/ec/ec-fix-openfd.t
index c32f9332137..04fdd802c62 100644
--- a/tests/basic/ec/ec-fix-openfd.t
+++ b/tests/basic/ec/ec-fix-openfd.t
@@ -37,6 +37,8 @@ TEST fd_open $fd 'rw' "$M0/test_file"
 TEST $CLI volume start $V0 force
 EXPECT_WITHIN $CHILD_UP_TIMEOUT "3" ec_child_up_count $V0 0
 
+sleep 1
+
 #Test the fd count
 EXPECT "0" get_fd_count $V0 $H0 $B0/${V0}0 test_file
 EXPECT "1" get_fd_count $V0 $H0 $B0/${V0}1 test_file
diff --git a/tests/basic/ec/ec-root-heal.t b/tests/basic/ec/ec-root-heal.t
index a133885ef1d..11ea7cdf9d4 100644
--- a/tests/basic/ec/ec-root-heal.t
+++ b/tests/basic/ec/ec-root-heal.t
@@ -22,7 +22,8 @@ EXPECT_WITHIN $CHILD_UP_TIMEOUT "6" ec_child_up_count_shd $V0 0
 # active heal
 TEST $CLI volume heal $V0 full
 #ls -l gives "Total" line so number of lines will be 1 more
-EXPECT_WITHIN $HEAL_TIMEOUT "^11$" num_entries $B0/${V0}6
+EXPECT_WITHIN $HEAL_TIMEOUT "^0$" get_pending_heal_count ${V0}
+EXPECT "^11$" num_entries $B0/${V0}6
 ec_version=$(get_hex_xattr trusted.ec.version $B0/${V0}0)
 EXPECT "$ec_version" get_hex_xattr trusted.ec.version $B0/${V0}1
 EXPECT "$ec_version" get_hex_xattr trusted.ec.version $B0/${V0}2
diff --git a/tests/basic/quick-read-with-upcall.t b/tests/basic/quick-read-with-upcall.t
index 318e93a1bf0..951faee02cc 100644
--- a/tests/basic/quick-read-with-upcall.t
+++ b/tests/basic/quick-read-with-upcall.t
@@ -37,12 +37,12 @@ TEST write_to "$M0/test.txt" "$D1"
 EXPECT "$D1" cat $M0/test.txt
 EXPECT "$D0" cat $M1/test.txt
 
-sleep 1
+sleep 2
 EXPECT "$D1" cat $M1/test.txt
 
 TEST $CLI volume set $V0 features.cache-invalidation on
-TEST $CLI volume set $V0 performance.qr-cache-timeout 60
-TEST $CLI volume set $V0 performance.md-cache-timeout 60
+TEST $CLI volume set $V0 performance.qr-cache-timeout 15
+TEST $CLI volume set $V0 performance.md-cache-timeout 15
 
 TEST write_to "$M0/test1.txt" "$D0"
 EXPECT "$D0" cat $M0/test1.txt
@@ -55,7 +55,7 @@ EXPECT "$D0" cat $M1/test1.txt
 sleep 1
 EXPECT "$D0" cat $M1/test1.txt
 
-sleep 60
+sleep 30
 EXPECT "$D1" cat $M1/test1.txt
 
 TEST $CLI volume set $V0 performance.cache-invalidation on
diff --git a/tests/bugs/distribute/bug-1161311.t b/tests/bugs/distribute/bug-1161311.t
index 9ae4fac342f..62796068928 100755
--- a/tests/bugs/distribute/bug-1161311.t
+++ b/tests/bugs/distribute/bug-1161311.t
@@ -76,14 +76,12 @@ TEST glusterfs -s $H0 --volfile-id $V0 $M0;
 TEST mkdir $M0/dir1
 TEST mkdir -p $M0/dir2/dir3
 
-# Create a large file (6.4 GB), so that rebalance takes time
-# Reading from /dev/urandom is slow, so we'll cat it together
-dd if=/dev/urandom of=/tmp/FILE2 bs=64k count=10240
-for i in {1..10}; do
-  cat /tmp/FILE2 >> $M0/dir1/FILE2
-done
-
-#dd if=/dev/urandom of=$M0/dir1/FILE2 bs=64k count=10240
+# Create a large file (8 GB), so that rebalance takes time
+# Since we really don't care about the contents of the file, we use fallocate
+# to generate the file much faster. We could also use truncate, which is even
+# faster, but rebalance could take advantage of an sparse file and migrate it
+# in an optimized way, but we don't want a fast migration.
+TEST fallocate -l 8G $M0/dir1/FILE2
 
 # Rename the file to create a linkto, for rebalance to
 # act on the file
diff --git a/tests/bugs/readdir-ahead/bug-1436090.t b/tests/bugs/readdir-ahead/bug-1436090.t
index 58e9093f1c3..e0877f15684 100755
--- a/tests/bugs/readdir-ahead/bug-1436090.t
+++ b/tests/bugs/readdir-ahead/bug-1436090.t
@@ -19,12 +19,12 @@ EXPECT 'Started' cluster_volinfo_field 1 $V0 'Status';
 TEST glusterfs -s $H1 --volfile-id $V0 $M0;
 TEST mkdir $M0/dir1
 
-# Create a large file (3.2 GB), so that rebalance takes time
-# Reading from /dev/urandom is slow, so we will cat it together
-dd if=/dev/urandom of=/tmp/FILE2 bs=64k count=10240
-for i in {1..5}; do
-  cat /tmp/FILE2 >> $M0/dir1/foo
-done
+# Create a large file (4 GB), so that rebalance takes time
+# Since we really don't care about the contents of the file, we use fallocate
+# to generate the file much faster. We could also use truncate, which is even
+# faster, but rebalance could take advantage of an sparse file and migrate it
+# in an optimized way, but we don't want a fast migration.
+TEST fallocate -l 4G $M0/dir1/foo
 
 TEST mv $M0/dir1/foo $M0/dir1/bar
 
diff --git a/tests/bugs/replicate/bug-1046624.t b/tests/bugs/replicate/bug-1046624.t
index 9ae40879228..e2762ea6764 100755
--- a/tests/bugs/replicate/bug-1046624.t
+++ b/tests/bugs/replicate/bug-1046624.t
@@ -25,11 +25,12 @@ TEST $CLI volume start $V0;
 EXPECT 'Started' volinfo_field $V0 'Status';
 
 ## Mount native
-TEST glusterfs --volfile-server=$H0 --volfile-id=$V0 $M0 --use-readdirp=no
+TEST ${GFS} --volfile-server=$H0 --volfile-id=$V0 --use-readdirp=no $M0
 
 TEST `echo "TEST-FILE" > $M0/File`
 TEST `mkdir $M0/Dir`
 TEST kill_brick $V0 $H0 $B0/${V0}-0
+EXPECT_WITHIN ${PROCESS_DOWN_TIMEOUT} "^0$" afr_child_up_status $V0 0
 
 TEST `ln -s $M0/File $M0/Link1`
 TEST `ln -s $M0/Dir $M0/Link2`
diff --git a/tests/bugs/replicate/bug-1130892.t b/tests/bugs/replicate/bug-1130892.t
index 0f57d669674..c7509f33cc2 100644
--- a/tests/bugs/replicate/bug-1130892.t
+++ b/tests/bugs/replicate/bug-1130892.t
@@ -17,9 +17,9 @@ EXPECT 'Created' volinfo_field $V0 'Status';
 TEST gluster volume set $V0 self-heal-daemon off
 
 # Enable Client side heal
-TEST $CLI volume set $V0 cluster.data-self-heal on
-TEST $CLI volume set $V0 cluster.metadata-self-heal on
-TEST $CLI volume set $V0 cluster.entry-self-heal on
+TEST $CLI volume set $V0 cluster.data-self-heal off
+TEST $CLI volume set $V0 cluster.metadata-self-heal off
+TEST $CLI volume set $V0 cluster.entry-self-heal off
 
 # Disable all perf-xlators
 TEST $CLI volume set $V0 performance.quick-read off
@@ -33,7 +33,7 @@ TEST $CLI volume start $V0;
 EXPECT 'Started' volinfo_field $V0 'Status';
 
 # FUSE Mount
-TEST glusterfs -s $H0 --volfile-id $V0 $M0
+TEST ${GFS} -s $H0 --volfile-id $V0 $M0
 
 # Create files and dirs
 TEST mkdir -p $M0/one/two/
@@ -41,6 +41,7 @@ TEST `echo "Carpe diem" > $M0/one/two/three`
 
 # Simulate disk-replacement
 TEST kill_brick $V0 $H0 $B0/${V0}-1
+EXPECT_WITHIN ${PROCESS_DOWN_TIMEOUT} "^0$" afr_child_up_status $V0 1
 TEST rm -rf $B0/${V0}-1/one
 TEST rm -rf $B0/${V0}-1/.glusterfs
 
@@ -55,10 +56,12 @@ EXPECT_WITHIN $CHILD_UP_TIMEOUT "1" afr_child_up_status $V0 1
 
 TEST stat $M0/one
 
+sleep 1
+
 # Check pending xattrs
 EXPECT "00000000" afr_get_specific_changelog_xattr $B0/${V0}-0/one trusted.afr.$V0-client-1 data
 EXPECT_NOT "00000000" afr_get_specific_changelog_xattr $B0/${V0}-0/one trusted.afr.$V0-client-1 entry
-EXPECT "00000000" afr_get_specific_changelog_xattr $B0/${V0}-0/one trusted.afr.$V0-client-1 metadata
+EXPECT_NOT "00000000" afr_get_specific_changelog_xattr $B0/${V0}-0/one trusted.afr.$V0-client-1 metadata
 
 TEST gluster volume set $V0 self-heal-daemon on
 
diff --git a/tests/bugs/replicate/bug-1180545.t b/tests/bugs/replicate/bug-1180545.t
index ccf51d8b8a6..5e40edd6c38 100644
--- a/tests/bugs/replicate/bug-1180545.t
+++ b/tests/bugs/replicate/bug-1180545.t
@@ -7,6 +7,31 @@
 . $(dirname $0)/../../volume.rc
 . $(dirname $0)/../../afr.rc
 
+function check_sh_entries() {
+        local expected="$1"
+        local count=
+        local good="0"
+        shift
+
+        for i in $*; do
+                count="$(count_sh_entries $i)"
+                if [[ "x${count}" == "x${expected}" ]]; then
+                        good="$((good + 1))"
+                fi
+        done
+        if [[ "x${good}" != "x${last_good}" ]]; then
+                last_good="${good}"
+# This triggers a sweep of the heal index. However if more than one brick
+# tries to heal the same directory at the same time, one of them will take
+# the lock and the other will give up, waiting for the next heal cycle, which
+# is set to 60 seconds (the minimum valid value). So, each time we detect
+# that one brick has completed the heal, we trigger another heal.
+                $CLI volume heal $V0
+        fi
+
+        echo "${good}"
+}
+
 cleanup;
 
 TEST glusterd
@@ -15,6 +40,7 @@ TEST pidof glusterd
 TEST $CLI volume create $V0 replica 2 $H0:$B0/brick{0,1}
 TEST $CLI volume set $V0 cluster.heal-timeout 60
 TEST $CLI volume set $V0 cluster.self-heal-daemon off
+TEST $CLI volume set $V0 stat-prefetch off
 TEST $CLI volume start $V0
 TEST $GFS --volfile-id=$V0 --volfile-server=$H0 $M0;
 
@@ -38,10 +64,13 @@ TEST $CLI volume set $V0 cluster.self-heal-daemon on
 EXPECT_WITHIN $PROCESS_UP_TIMEOUT "Y" glustershd_up_status
 EXPECT_WITHIN $CHILD_UP_TIMEOUT "1" afr_child_up_status_in_shd $V0 0
 EXPECT_WITHIN $CHILD_UP_TIMEOUT "1" afr_child_up_status_in_shd $V0 1
+
 TEST $CLI volume heal $V0
 
-EXPECT_WITHIN $HEAL_TIMEOUT '2' count_sh_entries $B0/brick0
-EXPECT_WITHIN $HEAL_TIMEOUT '2' count_sh_entries $B0/brick1
+last_good=""
+
+EXPECT_WITHIN $HEAL_TIMEOUT "2" check_sh_entries 2 $B0/brick{0,1}
+
 #Two entries for DIR and two for FILE
 EXPECT_WITHIN $HEAL_TIMEOUT "4" get_pending_heal_count $V0
 TEST diff <(ls $B0/brick0/DIR) <(ls $B0/brick1/DIR)
diff --git a/tests/bugs/replicate/bug-1221481-allow-fops-on-dir-split-brain.t b/tests/bugs/replicate/bug-1221481-allow-fops-on-dir-split-brain.t
index c4752c488f4..6ff471fbf15 100644
--- a/tests/bugs/replicate/bug-1221481-allow-fops-on-dir-split-brain.t
+++ b/tests/bugs/replicate/bug-1221481-allow-fops-on-dir-split-brain.t
@@ -11,19 +11,27 @@ TEST pidof glusterd;
 TEST $CLI volume create $V0 replica 2 $H0:$B0/${V0}{0,1};
 TEST $CLI volume set $V0 cluster.self-heal-daemon off
 TEST $CLI volume start $V0;
-TEST glusterfs --volfile-id=/$V0 --volfile-server=$H0 $M0 --attribute-timeout=0 --entry-timeout=0
+TEST $GFS --volfile-id=/$V0 --volfile-server=$H0 $M0
 TEST mkdir $M0/dir
 TEST touch $M0/dir/file{1..5}
 
 #Create entry split-brain
 TEST kill_brick $V0 $H0 $B0/$V0"1"
+EXPECT_WITHIN ${PROCESS_DOWN_TIMEOUT} "^0$" afr_child_up_status $V0 1
 TEST touch $M0/dir/FILE
+EXPECT_WITHIN ${UMOUNT_TIMEOUT} "^Y$" force_umount $M0
 TEST $CLI volume start $V0 force
+TEST $GFS --volfile-id=/$V0 --volfile-server=$H0 $M0
+EXPECT_WITHIN $CHILD_UP_TIMEOUT '1' afr_child_up_status_meta $M0 $V0-replicate-0 0
 EXPECT_WITHIN $CHILD_UP_TIMEOUT '1' afr_child_up_status_meta $M0 $V0-replicate-0 1
 TEST kill_brick $V0 $H0 $B0/$V0"0"
+EXPECT_WITHIN ${PROCESS_DOWN_TIMEOUT} "^0$" afr_child_up_status $V0 0
 TEST touch $M0/dir/FILE
+EXPECT_WITHIN ${UMOUNT_TIMEOUT} "^Y$" force_umount $M0
 TEST $CLI volume start $V0 force
+TEST $GFS --volfile-id=/$V0 --volfile-server=$H0 $M0
 EXPECT_WITHIN $CHILD_UP_TIMEOUT '1' afr_child_up_status_meta $M0 $V0-replicate-0 0
+EXPECT_WITHIN $CHILD_UP_TIMEOUT '1' afr_child_up_status_meta $M0 $V0-replicate-0 1
 
 cd $M0/dir
 EXPECT "6" echo $(ls | wc -l)
diff --git a/tests/bugs/replicate/bug-1493415-gfid-heal.t b/tests/bugs/replicate/bug-1493415-gfid-heal.t
index 125c35a7a21..8a79febf4b4 100644
--- a/tests/bugs/replicate/bug-1493415-gfid-heal.t
+++ b/tests/bugs/replicate/bug-1493415-gfid-heal.t
@@ -27,6 +27,11 @@ gfid_str_f1=$(gf_gfid_xattr_to_str $gfid_f1)
 TEST setfattr -x trusted.gfid $B0/${V0}1/f1
 TEST rm $B0/${V0}1/.glusterfs/${gfid_str_f1:0:2}/${gfid_str_f1:2:2}/$gfid_str_f1
 
+# storage/posix considers that a file without gfid changed less than a second
+# before doesn't exist, so we need to wait for a second to force posix to
+# consider that this is a valid file but without gfid.
+sleep 2
+
 # Assume there were no pending xattrs on parent dir due to 1st brick crashing
 # too. Then name heal from client must heal the gfid.
 EXPECT_WITHIN $UMOUNT_TIMEOUT "Y" force_umount $M0
@@ -52,6 +57,11 @@ TEST rm $B0/${V0}1/.glusterfs/${gfid_str_f2:0:2}/${gfid_str_f2:2:2}/$gfid_str_f2
 TEST setfattr -n trusted.afr.$V0-client-1 -v 0x000000000000000000000001 $B0/${V0}0/dir
 create_brick_xattrop_entry $B0/${V0}0 dir
 
+# storage/posix considers that a file without gfid changed less than a second
+# before doesn't exist, so we need to wait for a second to force posix to
+# consider that this is a valid file but without gfid.
+sleep 2
+
 #Trigger entry-heal via shd
 TEST $CLI volume set $V0 self-heal-daemon on
 EXPECT_WITHIN $PROCESS_UP_TIMEOUT "Y" glustershd_up_status
diff --git a/tests/bugs/replicate/bug-977797.t b/tests/bugs/replicate/bug-977797.t
index c2c0e67ebff..9a8f36c956c 100755
--- a/tests/bugs/replicate/bug-977797.t
+++ b/tests/bugs/replicate/bug-977797.t
@@ -30,7 +30,7 @@ TEST $CLI volume set $V0 cluster.data-self-heal on
 TEST $CLI volume set $V0 cluster.metadata-self-heal on
 TEST $CLI volume set $V0 cluster.entry-self-heal on
 
-TEST glusterfs --volfile-id=/$V0 --volfile-server=$H0 $M0 --attribute-timeout=0 --entry-timeout=0
+TEST $GFS --volfile-id=/$V0 --volfile-server=$H0 $M0
 
 
 TEST mkdir -p $M0/a
@@ -77,7 +77,7 @@ afr_get_specific_changelog_xattr $B0/$V0"2"/a/file trusted.afr.$V0-client-1 "dat
 EXPECT_WITHIN $HEAL_TIMEOUT "00000000" \
 afr_get_specific_changelog_xattr $B0/$V0"1"/a trusted.afr.$V0-client-0 "entry"
 
-EXPECT_WITHIN HEAL_TIMEOUT "00000000" \
+EXPECT_WITHIN $HEAL_TIMEOUT "00000000" \
 afr_get_specific_changelog_xattr $B0/$V0"1"/a trusted.afr.$V0-client-1 "entry"
 
 EXPECT_WITHIN $HEAL_TIMEOUT "00000000" \
diff --git a/tests/bugs/snapshot/bug-1109889.t b/tests/bugs/snapshot/bug-1109889.t
index 6b29cdd9eb1..5fdc7dc9506 100644
--- a/tests/bugs/snapshot/bug-1109889.t
+++ b/tests/bugs/snapshot/bug-1109889.t
@@ -19,9 +19,9 @@ TEST $CLI volume create $V0 $H0:$L1 $H0:$L2 $H0:$L3;
 
 TEST $CLI volume start $V0;
 
-TEST glusterfs --volfile-server=$H0 --volfile-id=$V0 $M0;
+TEST $GFS --volfile-server=$H0 --volfile-id=$V0 $M0;
 
-MOUNT_PID=`ps ax |grep "glusterfs --volfile-sever $H0 --volfile-id=$V0 $M0" | grep -v grep | awk '{print $1}' | head -1`
+MOUNT_PID=$(get_mount_process_pid $V0 $M0)
 
 for i in {1..10} ; do echo "file" > $M0/file$i ; done
 
diff --git a/tests/include.rc b/tests/include.rc
index 762c5e23251..9987ed10e83 100644
--- a/tests/include.rc
+++ b/tests/include.rc
@@ -1,3 +1,6 @@
+
+checkpoint_time="$(date +%s%N)"
+
 M0=${M0:=/mnt/glusterfs/0};   # 0th mount point for FUSE
 M1=${M1:=/mnt/glusterfs/1};   # 1st mount point for FUSE
 M2=${M2:=/mnt/glusterfs/2};   # 2nd mount point for FUSE
@@ -130,8 +133,8 @@ _GFS () {
 	while true; do
 		touch $mount_point/xy_zzy 2> /dev/null && break
 		i=$((i+1))
-		[ $i -lt 10 ] || break
-		sleep 1
+		[ $i -lt 100 ] || break
+		usleep 100000
 	done
 	rm -f $mount_point/xy_zzy
 	return $mount_ret
@@ -207,6 +210,7 @@ function test_header()
         dbg "=========================";
         dbg "TEST $t (line $TESTLINE): $*";
         saved_cmd="$*"
+        start_time="$(date +%s%N)"
 }
 
 
@@ -215,15 +219,18 @@ function test_footer()
         RET=$?
         local lineno=$1
         local err=$2
-
+        local end_time
+        local elapsed1
+        local elapsed2
+
+        end_time="$(date +%s%N)"
+        elapsed1="$(((start_time - checkpoint_time) / 1000000))"
+        elapsed2="$(((end_time - start_time) / 1000000))"
+        checkpoint_time="$end_time"
         if [ $RET -eq 0 ]; then
-                echo "ok $t, LINENUM:$lineno";
+                printf "ok %3d [%7d/%7d] <%4d> '%s'\n" "$t" "$elapsed1" "$elapsed2" "$lineno" "$saved_cmd";
         else
-                echo "not ok $t $err, LINENUM:$lineno";
-                # With DEBUG, this was already printed out, so skip it.
-                if [ x"$DEBUG" = x"0" ]; then
-                        echo "FAILED COMMAND: $saved_cmd"
-                fi
+                printf "not ok %3d [%7d/%7d] <%4d> '%s' -> '%s'\n" "$t" "$elapsed1" "$elapsed2" "$lineno" "$saved_cmd" "$err"
                 if [ "$EXIT_EARLY" = "1" ]; then
 			cleanup
                         exit $RET
@@ -356,12 +363,12 @@ function _EXPECT_WITHIN()
         a="";
         shift;
 
-        local endtime=$(( ${timeout}+`date +%s` ))
+        local endtime="$(( ${timeout}000000000 + $(date +%s%N) ))"
 
         # We *want* this to be globally visible.
         EW_RETRIES=0
 
-        while [ `date +%s` -lt $endtime ]; do
+        while [[ "$(date +%s%N)" < "$endtime" ]]; do
                 a=$("$@" | tail -1 ; exit ${PIPESTATUS[0]})
                 ## Check command success
                 if [ $? -ne 0 ]; then
@@ -371,7 +378,7 @@ function _EXPECT_WITHIN()
                 if [[ "$a" =~ $e ]]; then
                         break;
                 fi
-                sleep 1;
+                usleep 250000;
                 EW_RETRIES=$((EW_RETRIES+1))
         done
 
@@ -546,6 +553,7 @@ function process_pids() {
 
 function cleanup()
 {
+        local end_time
 
         # Prepare flags for umount
         case `uname -s` in
diff --git a/tests/volume.rc b/tests/volume.rc
index e4f47d92565..71d7fed9c87 100644
--- a/tests/volume.rc
+++ b/tests/volume.rc
@@ -116,16 +116,34 @@ function cleanup_statedump {
        #.vimrc friendly comment */
 }
 
+function wait_statedump_ready {
+        local maxtime="${1}000000000"
+        local pid="$2"
+        local deadline="$(($(date +%s%N) + maxtime))"
+        local fname
+
+        while [[ "$(date +%s%N)" < "$deadline" ]]; do
+                fname="$statedumpdir/$(ls $statedumpdir | grep -E "\.$pid\.dump\.")"
+                if [[ -f "$fname" ]]; then
+                        grep "^DUMP-END-TIME" "$fname" >/dev/null
+                        if [[ $? -eq 0 ]]; then
+                                echo $fname
+                                return
+                        fi
+                fi
+                usleep 100000
+        done
+
+        echo "nostatedump"
+}
+
 function generate_statedump {
         local fpath=""
         pid=$1
         #remove old stale statedumps
         cleanup_statedump $pid
         kill -USR1 $pid
-        #Wait till the statedump is generated
-        sleep 1
-        fname=$(ls $statedumpdir | grep -E "\.$pid\.dump\.")
-        echo $statedumpdir/$fname
+        wait_statedump_ready 3 $pid
 }
 
 function generate_mount_statedump {
@@ -309,15 +327,12 @@ function kill_brick {
 	local socket=$(cat $cmdline | tr '\0' '\n' | grep '\.socket$')
 
 	gf_attach -d $socket $brick
-	cnt=1
-        while [ "$cnt" -le "$PROCESS_UP_TIMEOUT" ] ;
-        do
-            online=`$CLI volume status $vol $host:$brick --xml | sed -ne 's/.*<status>\([01]\)<\/status>/\1/p'`
-            if [ $online -eq 0 ] ; then
-                break;
-            fi
-            cnt=$(( $cnt + 1 ))
-            sleep 1
+
+        local deadline="$(($(date +%s%N) + ${PROCESS_UP_TIMEOUT}000000000))"
+        while [[ "$(date +%s%N)" < "$deadline" ]]; do
+                if [[ "$(brick_up_status $vol $host $brick)" == "0" ]]; then
+                        break
+                fi
         done
 }
 
@@ -546,9 +561,8 @@ function volume_exists() {
 }
 
 function killall_gluster() {
-        pkill gluster
+        terminate_pids $(process_pids gluster)
         find $GLUSTERD_PIDFILEDIR -name '*.pid' | xargs rm -f
-        sleep 1
 }
 
 function afr_get_index_count {
@@ -868,7 +882,6 @@ function get_mount_active_size_value {
         local vol=$1
         local mount=$2
         local statedump=$(generate_mount_statedump $vol $mount)
-        sleep 1
         local val=$(grep "active_size" $statedump | cut -f2 -d'=' | tail -1)
         rm -f $statedump
         echo $val
@@ -878,7 +891,6 @@ function get_mount_lru_size_value {
         local vol=$1
         local mount=$2
         local statedump=$(generate_mount_statedump $vol $mount)
-        sleep 1
         local val=$(grep "lru_size" $statedump | cut -f2 -d'=' | tail -1)
         rm -f $statedump
         echo $val