tests: Add the command being 'TEST'ed in all gluster logs

Appends all commands being run under the test framework into the logs
with time stamps. Its a hack but I find it very useful to see what
sections of the logs (across all logs) need to be analysed between
execution of 2 commands.

Here's a sample output:
[2015-06-26 13:25:15.866764479]:++++++++++ G_LOG:tests/basic/afr/quorum.t: TEST: 46 ! test_write ++++++++++
[2015-06-26 13:25:15.872002] I [afr-common.c:1682:afr_local_discovery_cbk] 0-patchy-replicate-0: selecting local read_child patchy-client-1
[2015-06-26 13:25:15.874559] W [fuse-bridge.c:723:fuse_truncate_cbk] 0-glusterfs-fuse: 81: TRUNCATE() /a => -1 (Read-only file system)
[2015-06-26 13:25:15.880554623]:++++++++++ G_LOG:tests/basic/afr/quorum.t: TEST: 47 abc cat /mnt/glusterfs/0/b ++++++++++
[2015-06-26 13:25:15.897767878]:++++++++++ G_LOG:tests/basic/afr/quorum.t: TEST: 48 gluster --mode=script --wignore volume set patchy cluster.quorum-reads on ++++++++++[2015-06-26 13:25:15.994410] I [glusterfsd-mgmt.c:51:mgmt_cbk_spec] 0-mgmt: Volume file changed
[2015-06-26 13:25:17.098519] I [glusterfsd-mgmt.c:51:mgmt_cbk_spec] 0-mgmt: Volume file changed
[2015-06-26 13:25:17.099241] I [glusterfsd-mgmt.c:51:mgmt_cbk_spec] 0-mgmt: Volume file changed
[2015-06-26 13:25:17.099685] I [glusterfsd-mgmt.c:51:mgmt_cbk_spec] 0-mgmt: Volume file changed
[2015-06-26 13:25:17.100055] I [glusterfsd-mgmt.c:51:mgmt_cbk_spec] 0-mgmt: Volume file changed
[2015-06-26 13:25:17.105896] W [MSGID: 108003] [afr.c:94:fix_quorum_options] 0-patchy-replicate-0: quorum-type auto overriding quorum-count 2
[2015-06-26 13:25:17.105936] W [MSGID: 108001] [afr.c:189:reconfigure] 0-patchy-replicate-0: Client-quorum is not met
[2015-06-26 13:25:17.107438] I [glusterfsd-mgmt.c:1507:mgmt_getspec_cbk] 0-glusterfs: No change in volfile, continuing
[2015-06-26 13:25:17.108724] I [glusterfsd-mgmt.c:1507:mgmt_getspec_cbk] 0-glusterfs: No change in volfile, continuing
[2015-06-26 13:25:17.110082] I [glusterfsd-mgmt.c:1507:mgmt_getspec_cbk] 0-glusterfs: No change in volfile, continuing
[2015-06-26 13:25:17.110599] I [glusterfsd-mgmt.c:1507:mgmt_getspec_cbk] 0-glusterfs: No change in volfile, continuing
[2015-06-26 13:25:17.109678070]:++++++++++ G_LOG:tests/basic/afr/quorum.t: TEST: 49 1 mount_get_option_value /mnt/glusterfs/0 patchy-replicate-0 quorum-reads ++++++++++
[2015-06-26 13:25:17.117801] I [afr-common.c:1682:afr_local_discovery_cbk] 0-patchy-replicate-0: selecting local read_child patchy-client-1

Change-Id: Ib51284a0384508350579babaf1ae69cb372e0baa
BUG: 1233018
Signed-off-by: Ravishankar N <ravishankar@redhat.com>
Reviewed-on: http://review.gluster.org/10667
Tested-by: NetBSD Build System <jenkins@build.gluster.org>
Reviewed-by: Kaleb KEITHLEY <kkeithle@redhat.com>
Reviewed-by: Raghavendra Talur <rtalur@redhat.com>
This commit is contained in:
Ravishankar N 2015-05-09 07:23:09 +05:30 committed by Raghavendra Talur
parent 7a2fb3694d
commit b343155815

View File

@ -122,6 +122,21 @@ function dbg()
[ "x$DEBUG" = "x0" ] || echo "$*" >&2;
}
function G_LOG()
{
local logdir=`$CLI --print-logdir`
test -d $logdir
if [ $? != 0 ]; then
return
fi
local string="++++++++++ G_LOG:$0: TEST: $1 $2 ++++++++++"
string="`date -u +["%F %T.%N"]`:$string"
local i
for i in `find $logdir/ -type f`;
do
echo $string>>$i
done
}
function test_header()
{
@ -174,6 +189,7 @@ function _EXPECT()
shift;
local a=""
G_LOG $TESTLINE "$*";
test_header "$@";
e="$1";
@ -207,6 +223,7 @@ function _EXPECT_NOT()
shift;
local a=""
G_LOG $TESTLINE "$*";
test_header "$@";
e="$1";
@ -224,7 +241,7 @@ function _EXPECT_KEYWORD()
{
TESTLINE=$1;
shift;
G_LOG $TESTLINE "$*";
test_header "$@";
e="$1";
@ -234,13 +251,13 @@ function _EXPECT_KEYWORD()
test_footer;
}
function _TEST()
{
TESTLINE=$1;
shift;
local redirect=""
G_LOG $TESTLINE "$*";
test_header "$@";
if [ "$1" = "!" ]; then
@ -260,6 +277,7 @@ function _EXPECT_WITHIN()
local timeout=$1
shift;
G_LOG $TESTLINE "$*";
test_header "$@"
e=$1;
@ -826,7 +844,7 @@ log_newer()
logdir=`$CLI --print-logdir`
IFS="["
for date in `grep -hr "$msg" $logdir | awk -F '[\]]' '{print $1}'` ; do
for date in `grep -hr "$msg" $logdir | grep -v "G_LOG" | awk -F '[\]]' '{print $1}'` ; do
if [ `date -d "$date" +%s` -gt $ts ] ; then
return 0;
fi