From 89ea22174cb11f2e047048605b4d4773b6e020c9 Mon Sep 17 00:00:00 2001
From: Vincent Riquer <v.riquer@b2f-concept.com>
Date: Fri, 27 Jul 2012 15:34:52 +0200
Subject: [PATCH] 1.7.0: detailed logfile

---
 debian/changelog |  6 ++++
 remote-backup    | 72 ++++++++++++++++++++++++++----------------------
 2 files changed, 45 insertions(+), 33 deletions(-)

diff --git a/debian/changelog b/debian/changelog
index 1f985bb..4929331 100644
--- a/debian/changelog
+++ b/debian/changelog
@@ -1,3 +1,9 @@
+remote-backup (1.7) stable; urgency=low
+
+  * detailed logfile
+
+ -- Vincent Riquer <v.riquer@b2f-concept.com>  Fri, 27 Jul 2012 15:33:55 +0200
+
 remote-backup (1.6.3) stable; urgency=low
 
   * Syntax requires bash >= 3.1
diff --git a/remote-backup b/remote-backup
index 4c002ad..80235c6 100755
--- a/remote-backup
+++ b/remote-backup
@@ -13,7 +13,7 @@
 ###BEGIN: generic tool checker
 # FIXME: To reuse this function, be sure to edit this line (space separated
 # list).
-needed_tools="id echo mount rm mv cp touch rsync"
+needed_tools="id echo mount rm mv cp touch rsync snmptrap"
 #
 # One shall not need edit anything below this line
 ###
@@ -111,7 +111,7 @@ doBackup() {
 	source "$config"
 
 	backupIndex+=( "$NAME" )
-	echo "Debut de backup de ${REMOTE_LOCATION} vers ${SNAPSHOT_RW}/${NAME}/ a $(date +"%H:%M, le %d/%m/%Y")"
+	echo "$(date +"%Y-%m-%d:%H:%M:%S") ${REMOTE_LOCATION} to ${SNAPSHOT_RW}/${NAME}/"
 
 	if [[ "$REMOUNT" == "true" ]]
 	then
@@ -119,7 +119,7 @@ doBackup() {
 		mountMsg="$( $MOUNT -o remount,rw "$MOUNT_DEVICE" "$SNAPSHOT_RW" 2>&1 )" ;
 		if (( $? ))
 		then
-			echo "snapshot: could not remount $SNAPSHOT_RW readwrite" >&2
+			echo -e "$(date +%Y-%m-%d:%H:%M:%S)\tCould not remount $SNAPSHOT_RW readwrite" >&2
 			backupStatus+=( 4 )
 			backupStatusInfo+=( "$MOUNT_DEVICE: $mountMsg" )
 			return 1
@@ -128,6 +128,7 @@ doBackup() {
 
 	if [ ! -d "$SNAPSHOT_RW/$NAME" ]
 	then
+		echo -e "$(date +%Y-%m-%d:%H:%M:%S)\tCreating directory $SNAPSHOT_RW/$NAME"
 		mkdir -p "$SNAPSHOT_RW/$NAME"
 	fi
 
@@ -144,6 +145,7 @@ doBackup() {
 			then
 				backupStatus+=( 5 )
 				backupStatusInfo+=( "Process $(<"$SNAPSHOT_RW/$NAME/.lock") still running" )
+				echo -e "$(date +%Y-%m-%d:%H:%M:%S)\tProcess $(<"$SNAPSHOT_RW/$NAME/.lock") still running"
 			else
 				echo $$ > "$SNAPSHOT_RW/$NAME/.lock"
 				rotateBackup
@@ -164,28 +166,30 @@ doBackup() {
 		$MOUNT -o remount,ro "$MOUNT_DEVICE" "$SNAPSHOT_RW"
 		if (( $? ))
 		then
-			echo "snapshot: could not remount $SNAPSHOT_RW readonly" >&2
+			echo -e "$(date +%Y-%m-%d:%H:%M:%S)\tCould not remount $SNAPSHOT_RW readonly" >&2
 		fi
 	fi
 
-	echo "Fin de backup de ${REMOTE_LOCATION} vers ${SNAPSHOT_RW}/${NAME}/ a $(date +"%H:%M, le %d/%m/%Y")"
+	echo -e "$(date +%Y-%m-%d:%H:%M:%S) ${REMOTE_LOCATION} to ${SNAPSHOT_RW}/${NAME} done."
 	echo '-----------------------------------------------------------------------'
 }
 
 rotateBackup() {
 # rotating snapshots
+	echo -e "$(date +%Y-%m-%d:%H:%M:%S)\tRotate backups"
 	if [ -f "$SNAPSHOT_RW/$NAME/daily.0" ]
 	then
-		echo "Previous backup failed, skipping rotation."
+		echo -e "$(date +%Y-%m-%d:%H:%M:%S)\t\tPrevious backup failed, skipping rotation."
 		rm "$SNAPSHOT_RW/$NAME/daily.0"
 	elif [ -f "$SNAPSHOT_RW/$NAME/daily.0/unfinished.remote-backup" ]
 	then
-		echo "Previous backup interrupted, skipping rotation."
+		echo -e "$(date +%Y-%m-%d:%H:%M:%S)\t\tPrevious backup interrupted, skipping rotation."
 		rm "$SNAPSHOT_RW/$NAME/daily.0/unfinished.remote-backup"
 	else
 # step 1: delete the oldest snapshot, if it exists:
 		if [ -d "$SNAPSHOT_RW/$NAME/daily.${MAX_ROTATE}" ]
 		then
+			echo -e "$(date +%Y-%m-%d:%H:%M:%S)\t\tDeleting $SNAPSHOT_RW/$NAME/daily.${MAX_ROTATE}"
 			$RM -rf "$SNAPSHOT_RW/$NAME/daily.${MAX_ROTATE}"
 		fi
 
@@ -194,7 +198,11 @@ rotateBackup() {
 		do
 			if [ -d "$SNAPSHOT_RW/$NAME/daily.${backup_num}" ]
 			then
-				$MV -f "$SNAPSHOT_RW/$NAME/daily.${backup_num}" \
+				echo -e "$(date +%Y-%m-%d:%H:%M:%S)\t\tRename"		\
+					"$SNAPSHOT_RW/$NAME/daily.${backup_num}" 		\
+					"to"											\
+					"$SNAPSHOT_RW/$NAME/daily.$(( backup_num + 1 ))"
+				$MV -f "$SNAPSHOT_RW/$NAME/daily.${backup_num}"		\
 					"$SNAPSHOT_RW/$NAME/daily.$(( backup_num + 1 ))"
 			fi
 		done
@@ -204,7 +212,13 @@ rotateBackup() {
 runBackup() {
 # step 3: rsync from the system, linking to latest snapshot if files are
 # identical.
+	echo -e "$(date +%Y-%m-%d:%H:%M:%S)\tBuilding rsync command"
 	RSYNC_OPTS="-a --exclude-from=$EXCLUDES --bwlimit=$BWLIMIT"
+	echo -e "$(date +%Y-%m-%d:%H:%M:%S)\t\tBase options: $RSYNC_OPTS"
+	if [ -n "$ADDITIONAL_RSYNC_OPTS" ]
+	then
+		echo -e "$(date +%Y-%m-%d:%H:%M:%S)\t\tTarget-specific: $ADDITIONAL_RSYNC_OPTS"
+	fi
 	
 	if [[ $2 == PROTOCOLMISMATCH ]]
 	then
@@ -213,18 +227,21 @@ runBackup() {
 		proto29=1
 		MAX_ROTATE=1
 	fi
+	echo -e "$(date +%Y-%m-%d:%H:%M:%S)\t\tLooking for older snapshots"
+	for old_backup in "$SNAPSHOT_RW/$NAME/emerg".*
+	do
+		if [ -d "$old_backup" ] && ! (( proto29 ))
+		then
+			RSYNC_OPTS="$RSYNC_OPTS --link-dest=$old_backup"
+			echo -e "$(date +%Y-%m-%d:%H:%M:%S)\t\t\t$old_backup"
+		fi
+	done
 	for (( backup_num=1 ; backup_num <= MAX_ROTATE ; backup_num++ ))
 	do
 		if [ -d "$SNAPSHOT_RW/$NAME/daily.$backup_num" ]
 		then
 			RSYNC_OPTS="$RSYNC_OPTS --link-dest=$SNAPSHOT_RW/$NAME/daily.$backup_num"
-		fi
-	done
-	for old_backup in "$SNAPSHOT_RW/$NAME/emerg".*
-	do
-		if [ -d "$old_backup" ]
-		then
-			RSYNC_OPTS="$RSYNC_OPTS --link-dest=$old_backup"
+			echo -e "$(date +%Y-%m-%d:%H:%M:%S)\t\t\tdaily.$backup_num"
 		fi
 	done
 	if (( TIMEOUT ))
@@ -233,17 +250,19 @@ runBackup() {
 	else
 		RSYNC_OPTS="$RSYNC_OPTS --timeout=1800"
 	fi
+	echo -e "$(date +%Y-%m-%d:%H:%M:%S)\t\tTimeout is ${TIMEOUT:-1800} seconds"
 
 	# Not root? use --fake-super
 	if (( UID > 0 ))
 	then
-		echo "(info) running as user, using --fake-super."
+		echo -e "$(date +%Y-%m-%d:%H:%M:%S)\t\tRunning as user, using --fake-super."
 		RSYNC_OPTS="$RSYNC_OPTS --fake-super"
 	fi
 
-
+	echo -e "$(date +%Y-%m-%d:%H:%M:%S)\t\tComplete rsync command: $RSYNC $RSYNC_OPTS $ADDITIONAL_RSYNC_OPTS $REMOTE_LOCATION $SNAPSHOT_RW/$NAME/$1"
 	for (( try=1 ; try <= RETRY ; try++ ))
 	do
+		echo -e "$(date +%Y-%m-%d:%H:%M:%S)\tRunning rsync #$try/$RETRY"
 		$RSYNC							\
 			$RSYNC_OPTS					\
 			$ADDITIONAL_RSYNC_OPTS		\
@@ -263,18 +282,9 @@ runBackup() {
 			*)
 				if (( try == RETRY ))
 				then
-					cat <<-EOF
-
-						Trial $try / $RETRY failed, Giving up!
-
-					EOF
+					echo -e "$(date +%Y-%m-%d:%H:%M:%S)\t\tFailed, Giving up."
 				else
-					cat <<-EOF
-						
-						Trial $try / $RETRY failed.
-						Sleeping $RETRY_DELAY...
-
-					EOF
+					echo -e "$(date +%Y-%m-%d:%H:%M:%S)\t\tFailed. Sleeping $RETRY_DELAY..."
 					sleep $RETRY_DELAY
 				fi
 			;;
@@ -290,11 +300,7 @@ runBackup() {
 			then
 				failRsync PROTO_MISMATCH
 			else
-				cat <<-EOF
-
-					Rsync protocol mismatch, trying with only one --link-dest
-
-				EOF
+				echo -e "$(date +%Y-%m-%d:%H:%M:%S)\t\tRsync protocol mismatch, trying with only one --link-dest"
 				runBackup "$1" PROTOCOLMISMATCH
 			fi
 		;;