LU-1458 test: enable lustre_rsync debug log dump

* Make lustre_rsync dump its debug log to help debugging.
* Add debug messages in lr_move().

Signed-off-by: Bobi Jam <bobijam@whamcloud.com>
Change-Id: I0f26322b3a4677bcb1b09d09e0e7c0ea1b4dbe3d
Reviewed-on: http://review.whamcloud.com/3795
Reviewed-by: Fan Yong <yong.fan@whamcloud.com>
Tested-by: Hudson
Reviewed-by: Yu Jian <yujian@whamcloud.com>
Tested-by: Maloo <whamcloud.maloo@gmail.com>
Reviewed-by: Oleg Drokin <green@whamcloud.com>

diff --git a/lustre/tests/lustre-rsync-test.sh b/lustre/tests/lustre-rsync-test.sh
index de9f428..49918ae 100644 (file)
--- a/lustre/tests/lustre-rsync-test.sh
+++ b/lustre/tests/lustre-rsync-test.sh
@@ -42,7 +42,7 @@ build_test_filter
 
 export LRSYNC=${LRSYNC:-"$LUSTRE/utils/lustre_rsync"}
 [ ! -f "$LRSYNC" ] && export LRSYNC=$(which lustre_rsync)
 
 export LRSYNC=${LRSYNC:-"$LUSTRE/utils/lustre_rsync"}
 [ ! -f "$LRSYNC" ] && export LRSYNC=$(which lustre_rsync)

-export LRSYNC="$LRSYNC -v -c no" # -a
+export LRSYNC="$LRSYNC -v -c no -d 2"

 
 # control the time of tests
 DBENCH_TIME=${DBENCH_TIME:-60}  # No of seconds to run dbench
 
 # control the time of tests
 DBENCH_TIME=${DBENCH_TIME:-60}  # No of seconds to run dbench


@@ -108,7 +108,7 @@ check_xattr() {
 }
 
 check_diff() {
 }
 
 check_diff() {

-       local changelog_file=$LOGDIR/${TESTSUITE}.test_${3}.changelog
+       local changelog_file=$(generate_logname "changelog")

 
        if [ -e $1 -o -e $2 ]; then
                diff -rq -x "dev1" $1 $2
 
        if [ -e $1 -o -e $2 ]; then
                diff -rq -x "dev1" $1 $2


@@ -155,9 +155,11 @@ test_1() {
     # Device files
     #mknod $DIR/$tdir/dev1 b 8 1
 
     # Device files
     #mknod $DIR/$tdir/dev1 b 8 1
 

-    # Replicate
-    echo "Replication #1"
-    $LRSYNC -s $DIR -t $TGT -t $TGT2 -m $MDT0 -u $CL_USER -l $LREPL_LOG
+       # Replicate
+       local LRSYNC_LOG=$(generate_logname "lrsync_log")
+       echo "Replication #1"
+       $LRSYNC -s $DIR -t $TGT -t $TGT2 -m $MDT0 -u $CL_USER -l $LREPL_LOG \
+               -D $LRSYNC_LOG

 
     # Set attributes
     chmod 000 $DIR/$tdir/d2/file3
 
     # Set attributes
     chmod 000 $DIR/$tdir/d2/file3


@@ -172,8 +174,8 @@ test_1() {
         setfattr -n user.foo -v $value $DIR/$tdir/file5
     fi
 
         setfattr -n user.foo -v $value $DIR/$tdir/file5
     fi
 

-    echo "Replication #2"
-    $LRSYNC -l $LREPL_LOG
+       echo "Replication #2"
+       $LRSYNC -l $LREPL_LOG -D $LRSYNC_LOG

 
     if [[ "$xattr" != "no" ]]; then
         local xval1=$(get_xattr_value user.foo $TGT/$tdir/file5)
 
     if [[ "$xattr" != "no" ]]; then
         local xval1=$(get_xattr_value user.foo $TGT/$tdir/file5)


@@ -194,9 +196,9 @@ test_1() {
         RC=1
     fi
 
         RC=1
     fi
 

-    # Use diff to compare the source and the destination
-    check_diff $DIR/$tdir $TGT/$tdir 1
-    check_diff $DIR/$tdir $TGT2/$tdir 1
+       # Use diff to compare the source and the destination
+       check_diff $DIR/$tdir $TGT/$tdir
+       check_diff $DIR/$tdir $TGT2/$tdir

 
     fini_changelog
     cleanup_src_tgt
 
     fini_changelog
     cleanup_src_tgt


@@ -204,7 +206,7 @@ test_1() {
 }
 run_test 1 "Simple Replication"
 
 }
 run_test 1 "Simple Replication"
 

-# Test 2a - Replicate files created by dbench 
+# Test 2a - Replicate files created by dbench

 test_2a() {
     [ "$SLOW" = "no" ] && skip "Skipping slow test" && return
     init_src
 test_2a() {
     [ "$SLOW" = "no" ] && skip "Skipping slow test" && return
     init_src


@@ -213,12 +215,14 @@ test_2a() {
     # Run dbench
     sh rundbench -C -D $DIR/$tdir 2 -t $DBENCH_TIME || error "dbench failed!"
 
     # Run dbench
     sh rundbench -C -D $DIR/$tdir 2 -t $DBENCH_TIME || error "dbench failed!"
 

-    # Replicate the changes to $TGT
-    $LRSYNC -s $DIR -t $TGT -t $TGT2 -m $MDT0 -u $CL_USER -l $LREPL_LOG
+       local LRSYNC_LOG=$(generate_logname "lrsync_log")
+       # Replicate the changes to $TGT
+       $LRSYNC -s $DIR -t $TGT -t $TGT2 -m $MDT0 -u $CL_USER -l $LREPL_LOG \
+               -D $LRSYNC_LOG

 
 

-    # Use diff to compare the source and the destination
-    check_diff $DIR/$tdir $TGT/$tdir 2a
-    check_diff $DIR/$tdir $TGT2/$tdir 2a
+       # Use diff to compare the source and the destination
+       check_diff $DIR/$tdir $TGT/$tdir
+       check_diff $DIR/$tdir $TGT2/$tdir

 
     fini_changelog
     cleanup_src_tgt
 
     fini_changelog
     cleanup_src_tgt


@@ -243,9 +247,11 @@ test_2b() {
     echo Stopping dbench
     $KILL -SIGSTOP $child_pid
 
     echo Stopping dbench
     $KILL -SIGSTOP $child_pid
 

-    echo Starting replication
-    $LRSYNC -s $DIR -t $TGT -t $TGT2 -m $MDT0 -u $CL_USER -l $LREPL_LOG
-    check_diff $DIR/$tdir $TGT/$tdir 2b
+       local LRSYNC_LOG=$(generate_logname "lrsync_log")
+       echo Starting replication
+       $LRSYNC -s $DIR -t $TGT -t $TGT2 -m $MDT0 -u $CL_USER -l $LREPL_LOG \
+               -D $LRSYNC_LOG
+       check_diff $DIR/$tdir $TGT/$tdir

 
     echo Resuming dbench
     $KILL -SIGCONT $child_pid
 
     echo Resuming dbench
     $KILL -SIGCONT $child_pid


@@ -254,20 +260,20 @@ test_2b() {
     echo Stopping dbench
     $KILL -SIGSTOP $child_pid
 
     echo Stopping dbench
     $KILL -SIGSTOP $child_pid
 

-    echo Starting replication
-    $LRSYNC -l $LREPL_LOG
-    check_diff $DIR/$tdir $TGT/$tdir 2b
+       echo Starting replication
+       $LRSYNC -l $LREPL_LOG -D $LRSYNC_LOG
+       check_diff $DIR/$tdir $TGT/$tdir

 
     echo "Wait for dbench to finish"
     $KILL -SIGCONT $child_pid
     wait
 
 
     echo "Wait for dbench to finish"
     $KILL -SIGCONT $child_pid
     wait
 

-    # Replicate the changes to $TGT
-    echo Starting replication
-    $LRSYNC -l $LREPL_LOG
+       # Replicate the changes to $TGT
+       echo Starting replication
+       $LRSYNC -l $LREPL_LOG -D $LRSYNC_LOG

 
 

-    check_diff $DIR/$tdir $TGT/$tdir 2b
-    check_diff $DIR/$tdir $TGT2/$tdir 2b
+       check_diff $DIR/$tdir $TGT/$tdir
+       check_diff $DIR/$tdir $TGT2/$tdir

 
     fini_changelog
     cleanup_src_tgt
 
     fini_changelog
     cleanup_src_tgt


@@ -275,7 +281,7 @@ test_2b() {
 }
 run_test 2b "Replicate files changed by dbench."
 
 }
 run_test 2b "Replicate files changed by dbench."
 

-# Test 2c - Replicate files while dbench is running 
+# Test 2c - Replicate files while dbench is running

 test_2c() {
     [ "$SLOW" = "no" ] && skip "Skipping slow test" && return
     init_src
 test_2c() {
     [ "$SLOW" = "no" ] && skip "Skipping slow test" && return
     init_src


@@ -284,23 +290,25 @@ test_2c() {
     # Run dbench
     sh rundbench -C -D $DIR/$tdir 2 -t $DBENCH_TIME &
 
     # Run dbench
     sh rundbench -C -D $DIR/$tdir 2 -t $DBENCH_TIME &
 

-    # Replicate the changes to $TGT
-    sleep 10 # give dbench a headstart
-    local quit=0
-    while [ $quit -le 1 ];
-    do
-        echo "Running lustre_rsync"
-        $LRSYNC -s $DIR -t $TGT -t $TGT2 -m ${mds1_svc} -u $CL_USER -l $LREPL_LOG
-        sleep 5
-        pgrep dbench
-        if [ $? -ne 0 ]; then
-            quit=$(expr $quit + 1)
-        fi
-    done
+       local LRSYNC_LOG=$(generate_logname "lrsync_log")
+       # Replicate the changes to $TGT
+       sleep 10 # give dbench a headstart
+       local quit=0
+       while [ $quit -le 1 ];
+       do
+               echo "Running lustre_rsync"
+               $LRSYNC -s $DIR -t $TGT -t $TGT2 -m ${mds1_svc} -u $CL_USER \
+                       -l $LREPL_LOG -D $LRSYNC_LOG
+               sleep 5
+               pgrep dbench
+               if [ $? -ne 0 ]; then
+                       quit=$(expr $quit + 1)
+               fi
+       done

 
 

-    # Use diff to compare the source and the destination
-    check_diff $DIR/$tdir $TGT/$tdir 2c
-    check_diff $DIR/$tdir $TGT2/$tdir 2c
+       # Use diff to compare the source and the destination
+       check_diff $DIR/$tdir $TGT/$tdir
+       check_diff $DIR/$tdir $TGT2/$tdir

 
     fini_changelog
     cleanup_src_tgt
 
     fini_changelog
     cleanup_src_tgt


@@ -318,10 +326,12 @@ test_3a() {
     local numfiles=1000
     createmany -o $DIR/$tdir/$tfile $numfiles || error "createmany failed!"
 
     local numfiles=1000
     createmany -o $DIR/$tdir/$tfile $numfiles || error "createmany failed!"
 

-    # Replicate the changes to $TGT
-    $LRSYNC -s $DIR -t $TGT -t $TGT2 -m $MDT0 -u $CL_USER -l $LREPL_LOG
-    check_diff $DIR/$tdir $TGT/$tdir 3a
-    check_diff $DIR/$tdir $TGT2/$tdir 3a
+       local LRSYNC_LOG=$(generate_logname "lrsync_log")
+       # Replicate the changes to $TGT
+       $LRSYNC -s $DIR -t $TGT -t $TGT2 -m $MDT0 -u $CL_USER -l $LREPL_LOG \
+               -D $LRSYNC_LOG
+       check_diff $DIR/$tdir $TGT/$tdir
+       check_diff $DIR/$tdir $TGT2/$tdir

 
     fini_changelog
     cleanup_src_tgt
 
     fini_changelog
     cleanup_src_tgt


@@ -341,11 +351,13 @@ test_3b() {
     local threads=5
     writemany -q -a $DIR/$tdir/$tfile $time $threads || error "writemany failed!"
 
     local threads=5
     writemany -q -a $DIR/$tdir/$tfile $time $threads || error "writemany failed!"
 

-    # Replicate the changes to $TGT
-    $LRSYNC -s $DIR -t $TGT -t $TGT2 -m $MDT0 -u $CL_USER -l $LREPL_LOG
+       local LRSYNC_LOG=$(generate_logname "lrsync_log")
+       # Replicate the changes to $TGT
+       $LRSYNC -s $DIR -t $TGT -t $TGT2 -m $MDT0 -u $CL_USER -l $LREPL_LOG \
+               -D $LRSYNC_LOG

 
 

-    check_diff $DIR/$tdir $TGT/$tdir 3b
-    check_diff $DIR/$tdir $TGT2/$tdir 3b
+       check_diff $DIR/$tdir $TGT/$tdir
+       check_diff $DIR/$tdir $TGT2/$tdir

 
     fini_changelog
     cleanup_src_tgt
 
     fini_changelog
     cleanup_src_tgt


@@ -364,10 +376,12 @@ test_3c() {
     createmany -o $DIR/$tdir/$tfile $numfiles || error "createmany failed!"
     unlinkmany $DIR/$tdir/$tfile $numfiles || error "unlinkmany failed!"
 
     createmany -o $DIR/$tdir/$tfile $numfiles || error "createmany failed!"
     unlinkmany $DIR/$tdir/$tfile $numfiles || error "unlinkmany failed!"
 

-    # Replicate the changes to $TGT
-    $LRSYNC -s $DIR -t $TGT -t $TGT2 -m $MDT0  -u $CL_USER -l $LREPL_LOG
-    check_diff $DIR/$tdir $TGT/$tdir 3c
-    check_diff $DIR/$tdir $TGT2/$tdir 3c
+       local LRSYNC_LOG=$(generate_logname "lrsync_log")
+       # Replicate the changes to $TGT
+       $LRSYNC -s $DIR -t $TGT -t $TGT2 -m $MDT0  -u $CL_USER -l $LREPL_LOG \
+               -D $LRSYNC_LOG
+       check_diff $DIR/$tdir $TGT/$tdir
+       check_diff $DIR/$tdir $TGT2/$tdir

 
     fini_changelog
     cleanup_src_tgt
 
     fini_changelog
     cleanup_src_tgt


@@ -394,10 +408,12 @@ test_4() {
     child_pid=$(pgrep iozone)
     $KILL -SIGSTOP $child_pid
 
     child_pid=$(pgrep iozone)
     $KILL -SIGSTOP $child_pid
 

-    # Replicate the changes to $TGT
-    $LRSYNC -s $DIR -t $TGT -t $TGT2 -m $MDT0  -u $CL_USER -l $LREPL_LOG
-    check_diff $DIR/$tdir $TGT/$tdir 4
-    check_diff $DIR/$tdir $TGT2/$tdir 4
+       local LRSYNC_LOG=$(generate_logname "lrsync_log")
+       # Replicate the changes to $TGT
+       $LRSYNC -s $DIR -t $TGT -t $TGT2 -m $MDT0  -u $CL_USER -l $LREPL_LOG \
+               -D $LRSYNC_LOG
+       check_diff $DIR/$tdir $TGT/$tdir
+       check_diff $DIR/$tdir $TGT2/$tdir

 
     $KILL -SIGCONT $child_pid
     sleep 60
 
     $KILL -SIGCONT $child_pid
     sleep 60


@@ -416,9 +432,9 @@ test_4() {
       sleep 1;
     done
 
       sleep 1;
     done
 

-    $LRSYNC -l $LREPL_LOG
-    check_diff $DIR/$tdir $TGT/$tdir 4
-    check_diff $DIR/$tdir $TGT2/$tdir 4
+       $LRSYNC -l $LREPL_LOG -D $LRSYNC_LOG
+       check_diff $DIR/$tdir $TGT/$tdir
+       check_diff $DIR/$tdir $TGT2/$tdir

 
     fini_changelog
     cleanup_src_tgt
 
     fini_changelog
     cleanup_src_tgt


@@ -436,17 +452,18 @@ test_5a() {
     NUMTEST=2000
     createmany -o $DIR/$tdir/$tfile $NUMTEST
 
     NUMTEST=2000
     createmany -o $DIR/$tdir/$tfile $NUMTEST
 

-    # Replicate the changes to $TGT
-    
-    $LRSYNC -s $DIR -t $TGT -t $TGT2 -m $MDT0 -u $CL_USER -l $LREPL_LOG &
-    local child_pid=$!
-    sleep 30
-    $KILL -SIGHUP $child_pid
-    wait
-    $LRSYNC -l $LREPL_LOG
+       # Replicate the changes to $TGT
+       local LRSYNC_LOG=$(generate_logname "lrsync_log")
+       $LRSYNC -s $DIR -t $TGT -t $TGT2 -m $MDT0 -u $CL_USER -l $LREPL_LOG \
+               -D $LRSYNC_LOG &
+       local child_pid=$!
+       sleep 30
+       $KILL -SIGHUP $child_pid
+       wait
+       $LRSYNC -l $LREPL_LOG -D $LRSYNC_LOG

 
 

-    check_diff $DIR/$tdir $TGT/$tdir 5a
-    check_diff $DIR/$tdir $TGT2/$tdir 5a
+       check_diff $DIR/$tdir $TGT/$tdir
+       check_diff $DIR/$tdir $TGT2/$tdir

 
     fini_changelog
     cleanup_src_tgt
 
     fini_changelog
     cleanup_src_tgt


@@ -464,17 +481,18 @@ test_5b() {
     NUMTEST=2000
     createmany -o $DIR/$tdir/$tfile $NUMTEST
 
     NUMTEST=2000
     createmany -o $DIR/$tdir/$tfile $NUMTEST
 

-    # Replicate the changes to $TGT
-    
-    $LRSYNC -s $DIR -t $TGT -t $TGT2 -m $MDT0 -u $CL_USER -l $LREPL_LOG &
-    local child_pid=$!
-    sleep 30
-    $KILL -SIGKILL $child_pid
-    wait
-    $LRSYNC -l $LREPL_LOG
+       # Replicate the changes to $TGT
+       local LRSYNC_LOG=$(generate_logname "lrsync_log")
+       $LRSYNC -s $DIR -t $TGT -t $TGT2 -m $MDT0 -u $CL_USER -l $LREPL_LOG \
+               -D $LRSYNC_LOG &
+       local child_pid=$!
+       sleep 30
+       $KILL -SIGKILL $child_pid
+       wait
+       $LRSYNC -l $LREPL_LOG -D $LRSYNC_LOG

 
 

-    check_diff $DIR/$tdir $TGT/$tdir 5b
-    check_diff $DIR/$tdir $TGT2/$tdir 5b
+       check_diff $DIR/$tdir $TGT/$tdir
+       check_diff $DIR/$tdir $TGT2/$tdir

 
     fini_changelog
     cleanup_src_tgt
 
     fini_changelog
     cleanup_src_tgt


@@ -496,10 +514,12 @@ test_6() {
       i=$(expr $i + 1)
     done
 
       i=$(expr $i + 1)
     done
 

-    # Replicate the changes to $TGT
-    $LRSYNC -s $DIR -t $TGT -t $TGT2 -m $MDT0 -u $CL_USER -l $LREPL_LOG
-    check_diff $DIR/$tdir $TGT/$tdir 6
-    check_diff $DIR/$tdir $TGT2/$tdir 6
+       local LRSYNC_LOG=$(generate_logname "lrsync_log")
+       # Replicate the changes to $TGT
+       $LRSYNC -s $DIR -t $TGT -t $TGT2 -m $MDT0 -u $CL_USER -l $LREPL_LOG \
+               -D $LRSYNC_LOG
+       check_diff $DIR/$tdir $TGT/$tdir
+       check_diff $DIR/$tdir $TGT2/$tdir

 
     local count1=$(ls -l $TGT/$tdir/link0 | sed -r 's/ +/ /g' | cut -f 2 -d ' ')
     local count2=$(ls -l $TGT/$tdir/link0 | sed -r 's/ +/ /g' | cut -f 2 -d ' ')
 
     local count1=$(ls -l $TGT/$tdir/link0 | sed -r 's/ +/ /g' | cut -f 2 -d ' ')
     local count2=$(ls -l $TGT/$tdir/link0 | sed -r 's/ +/ /g' | cut -f 2 -d ' ')


@@ -523,26 +543,29 @@ test_7() {
     lfs setstripe -c $OSTCOUNT $DIR/$tdir
     createmany -o $DIR/$tdir/$tfile $NUMFILES
 
     lfs setstripe -c $OSTCOUNT $DIR/$tdir
     createmany -o $DIR/$tdir/$tfile $NUMFILES
 

-    # To simulate replication to another lustre filesystem, replicate
-    # the changes to $DIR/tgt. We can't turn off the changelogs
-    # while we are registered, so lustre_rsync better not try to 
-    # replicate the replication steps.  It seems ok :)
-
-    $LRSYNC -s $DIR -t $DIR/tgt -m $MDT0 -u $CL_USER -l $LREPL_LOG
-    check_diff ${DIR}/$tdir $DIR/tgt/$tdir 7
-
-    local i=0
-    while [ $i -lt $NUMFILES ];
-    do
-      local count=$(lfs getstripe $DIR/tgt/$tdir/${tfile}$i | awk '/stripe_count/ {print $2}')
-      if [ $count -ne $OSTCOUNT ]; then
-         error "Stripe size not replicated" 
-      fi
-      i=$(expr $i + 1)
-    done
-    fini_changelog
-    cleanup_src_tgt
-    return 0
+       # To simulate replication to another lustre filesystem, replicate
+       # the changes to $DIR/tgt. We can't turn off the changelogs
+       # while we are registered, so lustre_rsync better not try to
+       # replicate the replication steps.  It seems ok :)
+
+       local LRSYNC_LOG=$(generate_logname "lrsync_log")
+       $LRSYNC -s $DIR -t $DIR/tgt -m $MDT0 -u $CL_USER -l $LREPL_LOG \
+               -D $LRSYNC_LOG
+       check_diff ${DIR}/$tdir $DIR/tgt/$tdir
+
+       local i=0
+       while [ $i -lt $NUMFILES ];
+       do
+               local count=$(lfs getstripe $DIR/tgt/$tdir/${tfile}$i | \
+                             awk '/stripe_count/ {print $2}')
+               if [ $count -ne $OSTCOUNT ]; then
+                       error "Stripe size not replicated"
+               fi
+               i=$(expr $i + 1)
+       done
+       fini_changelog
+       cleanup_src_tgt
+       return 0

 }
 run_test 7 "lustre_rsync stripesize"
 
 }
 run_test 7 "lustre_rsync stripesize"
 


@@ -565,9 +588,11 @@ test_8() {
            mv $DIR/$tdir/d$i $DIR/$tdir/d0$i
     done
 
            mv $DIR/$tdir/d$i $DIR/$tdir/d0$i
     done
 

-    $LRSYNC -s $DIR -t $TGT -m $MDT0 -u $CL_USER -l $LREPL_LOG
+       local LRSYNC_LOG=$(generate_logname "lrsync_log")
+       $LRSYNC -s $DIR -t $TGT -m $MDT0 -u $CL_USER -l $LREPL_LOG \
+               -D $LRSYNC_LOG

 
 

-    check_diff ${DIR}/$tdir $TGT/$tdir 8
+       check_diff ${DIR}/$tdir $TGT/$tdir

 
     fini_changelog
     cleanup_src_tgt
 
     fini_changelog
     cleanup_src_tgt


@@ -582,15 +607,18 @@ test_9() {
     mkdir $DIR/$tdir/foo
     touch $DIR/$tdir/foo/a1
 
     mkdir $DIR/$tdir/foo
     touch $DIR/$tdir/foo/a1
 

-    $LRSYNC -s $DIR -t $TGT -m $MDT0 -u $CL_USER -l $LREPL_LOG
+       local LRSYNC_LOG=$(generate_logname "lrsync_log")
+       $LRSYNC -s $DIR -t $TGT -m $MDT0 -u $CL_USER -l $LREPL_LOG \
+               -D $LRSYNC_LOG

 
 

-    check_diff ${DIR}/$tdir $TGT/$tdir 9
+       check_diff ${DIR}/$tdir $TGT/$tdir

 
 

-    rm -rf $DIR/$tdir/foo
+       rm -rf $DIR/$tdir/foo

 
 

-    $LRSYNC -s $DIR -t $TGT -m $MDT0 -u $CL_USER -l $LREPL_LOG
+       $LRSYNC -s $DIR -t $TGT -m $MDT0 -u $CL_USER -l $LREPL_LOG \
+               -D $LRSYNC_LOG

 
 

-    check_diff ${DIR}/$tdir $TGT/$tdir 9
+       check_diff ${DIR}/$tdir $TGT/$tdir

 
     fini_changelog
     cleanup_src_tgt
 
     fini_changelog
     cleanup_src_tgt

diff --git a/lustre/tests/test-framework.sh b/lustre/tests/test-framework.sh
index 2f88949..02890af 100644 (file)
--- a/lustre/tests/test-framework.sh
+++ b/lustre/tests/test-framework.sh
@@ -5801,3 +5801,11 @@ mds_remove_ois() {
        ${rcmd} umount -d $mntpt || return 2
        # OI files will be recreated when mounted as lustre next time.
 }
        ${rcmd} umount -d $mntpt || return 2
        # OI files will be recreated when mounted as lustre next time.
 }

+
+# generate maloo upload-able log file name
+# \param logname specify unique part of file name
+generate_logname() {
+       local logname=${1:-"default_logname"}
+
+       echo "$TESTLOG_PREFIX.$TESTNAME.$logname.$(hostname -s).log"
+}

diff --git a/lustre/utils/lustre_rsync.c b/lustre/utils/lustre_rsync.c
index e352a45..c05a19e 100644 (file)
--- a/lustre/utils/lustre_rsync.c
+++ b/lustre/utils/lustre_rsync.c
@@ -198,6 +198,8 @@ char rsync[PATH_MAX];
 char rsync_ver[PATH_MAX];
 struct lr_parent_child_list *parents;
 
 char rsync_ver[PATH_MAX];
 struct lr_parent_child_list *parents;
 

+FILE *debug_log;
+

 /* Command line options */
 struct option long_opts[] = {
         {"source",      required_argument, 0, 's'},
 /* Command line options */
 struct option long_opts[] = {
         {"source",      required_argument, 0, 's'},


@@ -215,7 +217,8 @@ struct option long_opts[] = {
         {"start-recno", required_argument, 0, 'n'},
         {"abort-on-err",no_argument,       0, 'a'},
         {"debug",       required_argument, 0, 'd'},
         {"start-recno", required_argument, 0, 'n'},
         {"abort-on-err",no_argument,       0, 'a'},
         {"debug",       required_argument, 0, 'd'},

-        {0, 0, 0, 0}
+       {"debuglog",    required_argument, 0, 'D'},
+       {0, 0, 0, 0}

 };
 
 /* Command line usage */
 };
 
 /* Command line usage */


@@ -233,18 +236,31 @@ void lr_usage()
                 "\t--dry-run        don't write anything\n");
 }
 
                 "\t--dry-run        don't write anything\n");
 }
 

+#define DEBUG_ENTRY(info)                                                     \
+       lr_debug(D_TRACE, "***** Start %lld %s (%d) %s %s %s *****\n",         \
+                (info)->recno, changelog_type2str((info)->type),              \
+                (info)->type, (info)->tfid, (info)->pfid, (info)->name);
+
+#define DEBUG_EXIT(info, rc)                                                  \
+       lr_debug(D_TRACE, "##### End %lld %s (%d) %s %s %s rc=%d #####\n",     \
+                (info)->recno, changelog_type2str((info)->type),              \
+                (info)->type, (info)->tfid, (info)->pfid, (info)->name, rc);
+

 /* Print debug information. This is controlled by the value of the
    global variable 'debug' */
 void lr_debug(int level, const char *fmt, ...)
 {
 /* Print debug information. This is controlled by the value of the
    global variable 'debug' */
 void lr_debug(int level, const char *fmt, ...)
 {

-        va_list ap;
+       va_list ap;

 
 

-        if (level > debug)
-                return;
+       if (level > debug)
+               return;

 
 

-        va_start(ap, fmt);
-        vprintf(fmt, ap);
-        va_end(ap);
+       va_start(ap, fmt);
+       if (debug_log != NULL)
+               vfprintf(debug_log, fmt, ap);
+       else
+               vfprintf(stdout, fmt, ap);
+       va_end(ap);

 }
 
 
 }
 
 


@@ -814,7 +830,7 @@ int lr_create(struct lr_info *info)
                 if (rc1)
                         rc = rc1;
         }
                 if (rc1)
                         rc = rc1;
         }

-        return rc;
+       return rc;

 }
 
 /* Replicate a file remove (rmdir/unlink) operation */
 }
 
 /* Replicate a file remove (rmdir/unlink) operation */


@@ -855,7 +871,7 @@ int lr_remove(struct lr_info *info)
                         continue;
                 }
         }
                         continue;
                 }
         }

-        return rc;
+       return rc;

 }
 
 /* Replicate a rename/move operation. */
 }
 
 /* Replicate a rename/move operation. */


@@ -893,47 +909,56 @@ int lr_move(struct lr_info *info)
                                         status->ls_targets[info->target_no],
                                        info->path, info->name);
                         }
                                         status->ls_targets[info->target_no],
                                        info->path, info->name);
                         }

+                       lr_debug(DINFO, "dest path %s rc_dest=%d\n", info->dest,
+                                rc_dest);

                 }
                 if (rc_dest == -ENOENT) {
                         snprintf(info->dest, PATH_MAX, "%s/%s/%s",
                                 status->ls_targets[info->target_no],
                                SPECIAL_DIR, info->sfid);
                         special_dest = 1;
                 }
                 if (rc_dest == -ENOENT) {
                         snprintf(info->dest, PATH_MAX, "%s/%s/%s",
                                 status->ls_targets[info->target_no],
                                SPECIAL_DIR, info->sfid);
                         special_dest = 1;

+                       lr_debug(DINFO, "special dest %s\n", info->dest);

                 }
 
                 }
 

-                if (!rc_src)
-                        snprintf(info->src, PATH_MAX, "%s/%s/%s",
-                                status->ls_targets[info->target_no],
+               if (!rc_src) {
+                       snprintf(info->src, PATH_MAX, "%s/%s/%s",
+                               status->ls_targets[info->target_no],

                                srcpath, info->sname);
                                srcpath, info->sname);

+                       lr_debug(DINFO, "src path %s rc_src=%d\n", info->src,
+                                rc_src);
+               }

                 if (rc_src == -ENOENT || (access(info->src, F_OK) != 0 &&
                                           errno == ENOENT)) {
                         snprintf(info->src, PATH_MAX, "%s/%s/%s",
                                 status->ls_targets[info->target_no],
                                SPECIAL_DIR, info->sfid);
                         special_src = 1;
                 if (rc_src == -ENOENT || (access(info->src, F_OK) != 0 &&
                                           errno == ENOENT)) {
                         snprintf(info->src, PATH_MAX, "%s/%s/%s",
                                 status->ls_targets[info->target_no],
                                SPECIAL_DIR, info->sfid);
                         special_src = 1;

+                       lr_debug(DINFO, "special src %s\n", info->src);

                 }
 
                 rc1 = 0;
                 }
 
                 rc1 = 0;

+               errno = 0;

                 if (strcmp(info->src, info->dest) != 0) {
                         rc1 = rename(info->src, info->dest);
                         if (rc1 == -1)
                                 rc1 = -errno;
                 if (strcmp(info->src, info->dest) != 0) {
                         rc1 = rename(info->src, info->dest);
                         if (rc1 == -1)
                                 rc1 = -errno;

+                       lr_debug(DINFO, "rename returns %d\n", rc1);

                 }
 
                if (special_src) {
                 }
 
                if (special_src) {

-                       lr_remove_pc(info->spfid, info->sfid);
+                       rc1 = lr_remove_pc(info->spfid, info->sfid);

                        if (!special_dest)
                                lr_cascade_move(info->sfid, info->dest, info);
                 }
                if (special_dest)
                        if (!special_dest)
                                lr_cascade_move(info->sfid, info->dest, info);
                 }
                if (special_dest)

-                       lr_add_pc(info->pfid, info->sfid, info->name);
+                       rc1 = lr_add_pc(info->pfid, info->sfid, info->name);

 
                 lr_debug(DINFO, "move: %s [to] %s rc1=%d, errno=%d\n",
                          info->src, info->dest, rc1, errno);
                 if (rc1)
                         rc = rc1;
         }
 
                 lr_debug(DINFO, "move: %s [to] %s rc1=%d, errno=%d\n",
                          info->src, info->dest, rc1, errno);
                 if (rc1)
                         rc = rc1;
         }

-        return rc;
+       return rc;

 }
 
 /* Replicate a hard link */
 }
 
 /* Replicate a hard link */


@@ -1005,7 +1030,7 @@ int lr_link(struct lr_info *info)
                 if (rc1)
                         rc = rc1;
         }
                 if (rc1)
                         rc = rc1;
         }

-        return rc;
+       return rc;

 }
 
 /* Replicate file attributes */
 }
 
 /* Replicate file attributes */


@@ -1037,7 +1062,7 @@ int lr_setattr(struct lr_info *info)
                 if (rc1)
                         rc = rc1;
         }
                 if (rc1)
                         rc = rc1;
         }

-        return rc;
+       return rc;

 }
 
 /* Replicate xattrs */
 }
 
 /* Replicate xattrs */


@@ -1067,7 +1092,7 @@ int lr_setxattr(struct lr_info *info)
                         rc = rc1;
         }
 
                         rc = rc1;
         }
 

-        return rc;
+       return rc;

 }
 
 /* Parse a line of changelog entry */
 }
 
 /* Parse a line of changelog entry */


@@ -1465,6 +1490,8 @@ int lr_replicate()
                 if (dryrun)
                         continue;
 
                 if (dryrun)
                         continue;
 

+               DEBUG_ENTRY(info);
+

                 switch(info->type) {
                 case CL_CREATE:
                 case CL_MKDIR:
                 switch(info->type) {
                 case CL_CREATE:
                 case CL_MKDIR:


@@ -1498,6 +1525,7 @@ int lr_replicate()
                 default:
                         break;
                 }
                 default:
                         break;
                 }

+               DEBUG_EXIT(info, rc);

                 if (rc && rc != -ENOENT) {
                         lr_print_failure(info, rc);
                         errors++;
                 if (rc && rc != -ENOENT) {
                         lr_print_failure(info, rc);
                         errors++;


@@ -1552,8 +1580,8 @@ int main(int argc, char *argv[])
         if ((rc = lr_init_status()) != 0)
                 return rc;
 
         if ((rc = lr_init_status()) != 0)
                 return rc;
 

-        while ((rc = getopt_long(argc, argv, "as:t:m:u:l:vx:zc:ry:n:d:",
-                                long_opts, NULL)) >= 0) {
+       while ((rc = getopt_long(argc, argv, "as:t:m:u:l:vx:zc:ry:n:d:D:",
+                                long_opts, NULL)) >= 0) {

                 switch (rc) {
                 case 'a':
                         /* Assume absolute paths */
                 switch (rc) {
                 case 'a':
                         /* Assume absolute paths */


@@ -1643,6 +1671,15 @@ int main(int argc, char *argv[])
                         if (debug < 0 || debug > 2)
                                 debug = 0;
                         break;
                         if (debug < 0 || debug > 2)
                                 debug = 0;
                         break;

+               case 'D':
+                       /* Undocumented option debug log file */
+                       debug_log = fopen(optarg, "a");
+                       if (debug_log == NULL) {
+                               printf("Cannot open %s for debug log\n",
+                                      optarg);
+                               return -1;
+                       }
+                       break;

                 default:
                         fprintf(stderr, "error: %s: option '%s' "
                                 "unrecognized.\n", argv[0], argv[optind - 1]);
                 default:
                         fprintf(stderr, "error: %s: option '%s' "
                                 "unrecognized.\n", argv[0], argv[optind - 1]);


@@ -1689,5 +1726,7 @@ int main(int argc, char *argv[])
 
         rc = lr_replicate();
 
 
         rc = lr_replicate();
 

-        return rc;
+       if (debug_log != NULL)
+               fclose(debug_log);
+       return rc;

 }
 }