Bug 1416285 - EXPECT_WITHIN is taking too much time even if the result matches with expected value
Summary: EXPECT_WITHIN is taking too much time even if the result matches with expecte...
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: GlusterFS
Classification: Community
Component: tests
Version: 3.10
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Ashish Pandey
QA Contact:
URL:
Whiteboard:
Depends On: 1412549
Blocks:
TreeView+ depends on / blocked
 
Reported: 2017-01-25 07:05 UTC by Ashish Pandey
Modified: 2017-03-06 17:44 UTC (History)
2 users (show)

Fixed In Version: glusterfs-3.10.0
Doc Type: If docs needed, set a value
Doc Text:
Clone Of: 1412549
Environment:
Last Closed: 2017-03-06 17:44:28 UTC
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:


Attachments (Terms of Use)

Description Ashish Pandey 2017-01-25 07:05:52 UTC
+++ This bug was initially created as a clone of Bug #1412549 +++

Description of problem:

    tests/include : EXPECT_WITHIN takes full time even if expression matches
    
    Problem: For all the tests using get_pending_heal_count, EXPECT_WITHIN
    is taking full time given to it even if the heal count matches with
    expected value.
    



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


How reproducible:
100%

Steps to Reproduce:
1. 
2. 
3.

Actual results:


Expected results:


Additional info:

--- Additional comment from Ashish Pandey on 2017-01-12 04:36:06 EST ---

    


    RC: 
    In most of the tests, to check heal count, wildcards are
    being used. In EXPECT_WITHIN, in if condition, when we use it in
    double quotes (" "), it gives string with wildcards which does not
    match with the output of get_pending_heal_count.
    For example, (0 =~ ^0$).
    So, "while" loop was running for full time and at the end, after
    coming out of loop, in next if condition it was mathing with the
    expression without quotes. That is why it was passing.

function _EXPECT_WITHIN()
{
        TESTLINE=$1
        shift;

        local timeout=$1
        shift;

        G_LOG $TESTLINE "$@";
        test_header "$@"

        e=$1;
        a="";
        shift;

        local endtime=$(( ${timeout}+`date +%s` ))

        while [ `date +%s` -lt $endtime ]; do
                a=$("$@" | tail -1 ; exit ${PIPESTATUS[0]})
                ## Check command success
                if [ $? -ne 0 ]; then
                        break;
                fi

                ## Check match success

                if [[ "$a" =~ "$e" ]]; then <<<<<<<<<<< This is the issue
                        break;
                fi
                sleep 1;
        done

So after this while loop actually, it is test_expect_footer which checks and matches the value. This function is using expression without double quotes.

function test_expect_footer()
{
        local lineno=$1
        local e=$2
        local a=$3
        local err=""

        if ! [[ "$a" =~ $e ]]; then
                err="Got \"$a\" instead of \"$e\""
        fi
        [[ "$a" =~ $e ]];

        test_footer "$lineno" "$err";
}



Solution :    
    Remove double quotes in "if condition" in EXPECT_WITHIN and match
    as we are matching it in test_expect_footer.

--- Additional comment from Ashish Pandey on 2017-01-12 04:38:43 EST ---


This is the comparison in time taken in both the cases - 

Without double quotes - 

[root@apandey glusterfs]# time prove tests/basic/ec/ec-background-heals.t 
tests/basic/ec/ec-background-heals.t .. ok         
All tests successful.
Files=1, Tests=71, 132 wallclock secs ( 0.04 usr  0.01 sys +  2.13 cusr  1.10 csys =  3.28 CPU)
Result: PASS

real	2m12.354s
user	0m2.242s
sys	0m1.124s


With double quotes - 


[root@apandey glusterfs]# 
[root@apandey glusterfs]# 
[root@apandey glusterfs]# time prove tests/basic/ec/ec-background-heals.t 
tests/basic/ec/ec-background-heals.t .. ok     
All tests successful.
Files=1, Tests=71, 610 wallclock secs ( 0.03 usr  0.00 sys + 14.13 cusr  5.63 csys = 19.79 CPU)
Result: PASS

real	10m10.239s
user	0m14.214s
sys	0m5.638s

--- Additional comment from Worker Ant on 2017-01-12 04:42:50 EST ---

REVIEW: http://review.gluster.org/16382 (tests/include : EXPECT_WITHIN takes full time even if expression matches) posted (#1) for review on master by Ashish Pandey (aspandey@redhat.com)

--- Additional comment from Worker Ant on 2017-01-24 07:14:23 EST ---

REVIEW: https://review.gluster.org/16382 (tests/include : EXPECT_WITHIN takes full time even if expression matches) posted (#2) for review on master by Ashish Pandey (aspandey@redhat.com)

--- Additional comment from Worker Ant on 2017-01-25 01:49:50 EST ---

COMMIT: https://review.gluster.org/16382 committed in master by Raghavendra Talur (rtalur@redhat.com) 
------
commit 07b34dd5c2f2c6eed4669472dd5af1063f4f224b
Author: Ashish Pandey <aspandey@redhat.com>
Date:   Thu Jan 12 14:48:28 2017 +0530

    tests/include : EXPECT_WITHIN takes full time even if expression matches
    
    Problem: For all the tests using get_pending_heal_count, EXPECT_WITHIN
    is taking full time given to it even if the heal count matches with
    expected value.
    
    Solution:
    RC - In most of the tests, to check heal count, wildcards are
    being used. In EXPECT_WITHIN, in if condition, when we use it in
    double quotes (" "), it gives string with wildcards which does not
    match with the output of get_pending_heal_count.
    For example, (0 =~ ^0$).
    So, "while" loop was running for full time and at the end, after
    coming out of loop, in next if condition it was matching with the
    expression without quotes. That is why it was passing.
    
    Remove double quotes in "if condition" in EXPECT_WITHIN and match
    as we are matching it in test_expect_footer.
    
    Change-Id: Ia161594774d05b9b888efb2f7ed1950590d8ac1b
    BUG: 1412549
    Signed-off-by: Ashish Pandey <aspandey@redhat.com>
    Reviewed-on: https://review.gluster.org/16382
    Smoke: Gluster Build System <jenkins@build.gluster.org>
    Reviewed-by: Jeff Darcy <jdarcy@redhat.com>
    NetBSD-regression: NetBSD Build System <jenkins@build.gluster.org>
    CentOS-regression: Gluster Build System <jenkins@build.gluster.org>
    Reviewed-by: Raghavendra Talur <rtalur@redhat.com>

Comment 1 Worker Ant 2017-01-25 07:11:46 UTC
REVIEW: https://review.gluster.org/16467 (tests/include : EXPECT_WITHIN takes full time even if expression matches) posted (#1) for review on release-3.10 by Ashish Pandey (aspandey@redhat.com)

Comment 2 Worker Ant 2017-01-25 18:36:33 UTC
COMMIT: https://review.gluster.org/16467 committed in release-3.10 by Shyamsundar Ranganathan (srangana@redhat.com) 
------
commit 10076acaddfa611214e42e0402c3578bc69cada9
Author: Ashish Pandey <aspandey@redhat.com>
Date:   Thu Jan 12 14:48:28 2017 +0530

    tests/include : EXPECT_WITHIN takes full time even if expression matches
    
    Problem: For all the tests using get_pending_heal_count, EXPECT_WITHIN
    is taking full time given to it even if the heal count matches with
    expected value.
    
    Solution:
    RC - In most of the tests, to check heal count, wildcards are
    being used. In EXPECT_WITHIN, in if condition, when we use it in
    double quotes (" "), it gives string with wildcards which does not
    match with the output of get_pending_heal_count.
    For example, (0 =~ ^0$).
    So, "while" loop was running for full time and at the end, after
    coming out of loop, in next if condition it was matching with the
    expression without quotes. That is why it was passing.
    
    Remove double quotes in "if condition" in EXPECT_WITHIN and match
    as we are matching it in test_expect_footer.
    
    >Change-Id: Ia161594774d05b9b888efb2f7ed1950590d8ac1b
    >BUG: 1412549
    >Signed-off-by: Ashish Pandey <aspandey@redhat.com>
    >Reviewed-on: https://review.gluster.org/16382
    >Smoke: Gluster Build System <jenkins@build.gluster.org>
    >Reviewed-by: Jeff Darcy <jdarcy@redhat.com>
    >NetBSD-regression: NetBSD Build System <jenkins@build.gluster.org>
    >CentOS-regression: Gluster Build System <jenkins@build.gluster.org>
    >Reviewed-by: Raghavendra Talur <rtalur@redhat.com>
    >Signed-off-by: Ashish Pandey <aspandey@redhat.com>
    
    Change-Id: Ia161594774d05b9b888efb2f7ed1950590d8ac1b
    BUG: 1416285
    Signed-off-by: Ashish Pandey <aspandey@redhat.com>
    Reviewed-on: https://review.gluster.org/16467
    Smoke: Gluster Build System <jenkins@build.gluster.org>
    NetBSD-regression: NetBSD Build System <jenkins@build.gluster.org>
    CentOS-regression: Gluster Build System <jenkins@build.gluster.org>
    Reviewed-by: Shyamsundar Ranganathan <srangana@redhat.com>

Comment 3 Shyamsundar 2017-03-06 17:44:28 UTC
This bug is getting closed because a release has been made available that should address the reported issue. In case the problem is still not fixed with glusterfs-3.10.0, please open a new bug report.

glusterfs-3.10.0 has been announced on the Gluster mailinglists [1], packages for several distributions should become available in the near future. Keep an eye on the Gluster Users mailinglist [2] and the update infrastructure for your distribution.

[1] http://lists.gluster.org/pipermail/gluster-users/2017-February/030119.html
[2] https://www.gluster.org/pipermail/gluster-users/


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