Merge pull request #268 from github/improved-logging

Prepend colorized input to logging data

Author: gamefiend

backup.config-example

@@ -42,6 +42,11 @@ GHE_NUM_SNAPSHOTS=10
 #
 #GHE_EXTRA_RSYNC_OPTS=""
 
+
+# If set to 'yes', logging output will be colorized.
+#
+#OUTPUT_COLOR=no
+
 # If set to 'no', GHE_DATA_DIR will not be created automatically
 # and restore/backup will exit 8
 #

bin/ghe-backup

@@ -67,21 +67,18 @@ trap 'rm -rf src dest1 dest2' EXIT
 mkdir -p src
 touch src/testfile
 if ! ln -s /data/does/not/exist/hooks/ src/ >/dev/null 2>&1; then
-  echo "Error: the filesystem containing $GHE_DATA_DIR does not support symbolic links." 1>&2
-  echo "Git repositories contain symbolic links that need to be preserved during a backup." 1>&2
+  log_error "Error: the filesystem containing $GHE_DATA_DIR does not support symbolic links. \nGit repositories contain symbolic links that need to be preserved during a backup." 1>&2
   exit 1
 fi
 
 if ! output=$(rsync -a src/ dest1 2>&1 && rsync -av src/ --link-dest=../dest1 dest2 2>&1); then
-  echo "Error: rsync encountered an error that could indicate a problem with permissions," 1>&2
-  echo "hard links, symbolic links, or another issue that may affect backups." 1>&2
+  log_error "Error: rsync encountered an error that could indicate a problem with permissions,\n hard links, symbolic links, or another issue that may affect backups." 1>&2
   echo "$output"
   exit 1
 fi
 
 if [ "$(ls -il dest1/testfile | awk '{ print $1 }')" != "$(ls -il dest2/testfile | awk '{ print $1 }')" ]; then
-  echo "Error: the filesystem containing $GHE_DATA_DIR does not support hard links." 1>&2
-  echo "Backup Utilities use hard links to store backup data efficiently." 1>&2
+  log_error "Error: the filesystem containing $GHE_DATA_DIR does not support hard links.\n Backup Utilities use hard links to store backup data efficiently." 1>&2
   exit 1
 fi
 rm -rf src dest1 dest2
@@ -122,9 +119,8 @@ ghe_restore_check
 
 # Check to see if there is a running backup
 if [ -h ../in-progress ]; then
-  echo "Error: detected a backup already in progress from a previous version of ghe-backup." 1>&2
-  echo "If there is no backup in progress anymore, please remove" 1>&2
-  echo "the $GHE_DATA_DIR/in-progress file and try again." 1>&2
+
+  log_error "Error: detected a backup already in progress from a previous version of ghe-backup. \nIf there is no backup in progress anymore, please remove \nthe $GHE_DATA_DIR/in-progress file." 1>&2
   exit 1
 fi
 
@@ -137,20 +133,16 @@ if [ -f ../in-progress ]; then
     # will clean up the failed backup.
     unlink ../in-progress
   else
-    echo "Error: A backup of $GHE_HOSTNAME may still be running on PID $pid." 1>&2
-    echo 1>&2
-    echo "  If PID $pid is not a process related to the backup utilities, please remove" 1>&2
-    echo "  the $GHE_DATA_DIR/in-progress file and try again." 1>&2
+    log_error "Error: A backup of $GHE_HOSTNAME may still be running on PID $pid. \nIf PID $pid is not a process related to the backup utilities, please remove \nthe $GHE_DATA_DIR/in-progress file and try again." 1>&2
     exit 1
   fi
 fi
 
 echo "$GHE_SNAPSHOT_TIMESTAMP $$" > ../in-progress
 echo "$GHE_SNAPSHOT_TIMESTAMP $$" > ${GHE_DATA_DIR}/in-progress-backup
 
-START_TIME=$(date +%s)
-echo 'Start time:' $START_TIME
-echo "Starting backup of $GHE_HOSTNAME with backup-utils v$BACKUP_UTILS_VERSION in snapshot $GHE_SNAPSHOT_TIMESTAMP"
+log_info "Starting backup of $GHE_HOSTNAME with backup-utils v$BACKUP_UTILS_VERSION in snapshot $GHE_SNAPSHOT_TIMESTAMP"
+
 
 # Perform a host connection check and establish the remote appliance version.
 # The version is available in the GHE_REMOTE_VERSION variable and also written
@@ -173,19 +165,22 @@ echo "$GHE_BACKUP_STRATEGY" > strategy
 # Create benchmark file
 bm_init > /dev/null
 
+START_TIME=$(date +%s)
+log_info "Starting backup of $GHE_HOSTNAME with backup-utils v$BACKUP_UTILS_VERSION"
+
 ghe-backup-store-version  ||
-echo "Warning: storing backup-utils version remotely failed."
+log_warn "Warning: storing backup-utils version remotely failed."
 
-echo "Backing up GitHub settings ..."
+log_info "Backing up GitHub settings ..."
 ghe-backup-settings || failures="$failures settings"
 
-echo "Backing up SSH authorized keys ..."
+log_info "Backing up SSH authorized keys ..."
 bm_start "ghe-export-authorized-keys"
 ghe-ssh "$GHE_HOSTNAME" -- 'ghe-export-authorized-keys' > authorized-keys.json ||
 failures="$failures authorized-keys"
 bm_end "ghe-export-authorized-keys"
 
-echo "Backing up SSH host keys ..."
+log_info "Backing up SSH host keys ..."
 bm_start "ghe-export-ssh-host-keys"
 ghe-ssh "$GHE_HOSTNAME" -- 'ghe-export-ssh-host-keys' > ssh-host-keys.tar ||
 failures="$failures ssh-host-keys"
@@ -194,45 +189,52 @@ bm_end "ghe-export-ssh-host-keys"
 ghe-backup-mysql || failures="$failures mysql"
 
 if ghe-ssh "$GHE_HOSTNAME" -- 'ghe-config --true app.actions.enabled'; then
-  echo "Backing up MSSQL databases ..."
+  log_info "Backing up MSSQL databases ..."
   ghe-backup-mssql 1>&3 || failures="$failures mssql"
 
-  echo "Backing up Actions data ..."
+  log_info "Backing up Actions data ..."
   ghe-backup-actions 1>&3 || failures="$failures actions"
 fi
 
 if ghe-ssh "$GHE_HOSTNAME" -- 'ghe-config --true app.minio.enabled'; then
-  echo "Backing up Minio data ..."
+  log_info "Backing up Minio data ..."
   ghe-backup-minio 1>&3 || failures="$failures minio"
 fi
 
+cmd_title=$(log_info "Backing up Redis database ...")
 commands=("
-echo \"Backing up Redis database ...\"
+echo \"$cmd_title\"
 ghe-backup-redis > redis.rdb || printf %s \"redis \" >> \"$failures_file\"")
 
+cmd_title=$(log_info "Backing up audit log ...")
 commands+=("
-echo \"Backing up audit log ...\"
+echo \"$cmd_title\"
 ghe-backup-es-audit-log || printf %s \"audit-log \" >> \"$failures_file\"")
 
+cmd_title=$(log_info "Backing up Git repositories ...")
 commands+=("
-echo \"Backing up Git repositories ...\"
+echo \"$cmd_title\"
 ghe-backup-repositories || printf %s \"repositories \" >> \"$failures_file\"")
 
+cmd_title=$(log_info "Backing up GitHub Pages artifacts ...")
 commands+=("
-echo \"Backing up GitHub Pages artifacts ...\"
+echo \"$cmd_title\"
 ghe-backup-pages || printf %s \"pages \" >> \"$failures_file\"")
 
+cmd_title=$(log_info "Backing up storage data ...")
 commands+=("
-echo \"Backing up storage data ...\"
+echo \"$cmd_title\"
 ghe-backup-storage || printf %s \"storage \" >> \"$failures_file\"")
 
+cmd_title=$(log_info "Backing up custom Git hooks ...")
 commands+=("
-echo \"Backing up custom Git hooks ...\"
+echo \"$cmd_title\"
 ghe-backup-git-hooks || printf %s \"git-hooks \" >> \"$failures_file\"")
 
 if [ "$GHE_BACKUP_STRATEGY" = "rsync" ]; then
+  cmd_title=$(log_info "Backing up Elasticsearch indices ...")
   commands+=("
-  echo \"Backing up Elasticsearch indices ...\"
+  echo \"$cmd_title\"
   ghe-backup-es-rsync || printf %s \"elasticsearch \" >> \"$failures_file\"")
 fi
 
@@ -250,6 +252,7 @@ fi
 
 # git fsck repositories after the backup
 if [ "$GHE_BACKUP_FSCK" = "yes" ]; then
+  log_info "Running git fsck on repositories ..."
   ghe-backup-fsck $GHE_SNAPSHOT_DIR || failures="$failures fsck"
 fi
 
@@ -265,26 +268,25 @@ if [ -z "$failures" ]; then
   ghe-prune-snapshots
 fi
 
-END_TIME=$(date +%s)
-echo 'End time:' $END_TIME
-echo 'Runtime:' $(($END_TIME - $START_TIME)) 'seconds'
-
-echo "Completed backup of $GHE_HOSTNAME in snapshot $GHE_SNAPSHOT_TIMESTAMP at $(date +"%H:%M:%S")"
+log_info "Completed backup of $GHE_HOSTNAME in snapshot $GHE_SNAPSHOT_TIMESTAMP at $(date +"%H:%M:%S")"
 
 # Exit non-zero and list the steps that failed.
 if [ -z "$failures" ]; then
   ghe_remote_logger "Completed backup from $(hostname) / snapshot $GHE_SNAPSHOT_TIMESTAMP successfully."
 else
   steps="$(echo $failures | sed 's/ /, /g')"
   ghe_remote_logger "Completed backup from $(hostname) / snapshot $GHE_SNAPSHOT_TIMESTAMP with failures: ${steps}."
-  echo "Error: Snapshot incomplete. Some steps failed: ${steps}. "
+  log_error "Error: Snapshot incomplete. Some steps failed: ${steps}. "
   exit 1
 fi
 
 # Detect if the created backup contains any leaked ssh keys
-echo "Checking for leaked ssh keys ..."
+log_info "Checking for leaked ssh keys ..."
 ghe-detect-leaked-ssh-keys -s "$GHE_SNAPSHOT_DIR" || true
 
+END_TIME=$(date +%s)
+log_info "Runtime: $((${END_TIME} - ${START_TIME})) seconds"
+log_info "Backup of $GHE_HOSTNAME finished."
 # Make sure we exit zero after the conditional
 true
 

bin/ghe-host-check

@@ -97,7 +97,7 @@ if "$CLUSTER"; then
   distinct_versions=$(echo "$node_version_list" | awk '{split($0, a, ":"); print a[2]}' | awk '{print $4}' | uniq | wc -l)
   if [ "$distinct_versions" -ne 1 ]; then
     echo "$node_version_list" 1>&2
-    echo "Error: Not all nodes are running the same version! Please ensure all nodes are running the same version before using backup-utils." 1>&2
+    echo "Error: Not all nodes are running the same version! Please ensure all nodes are running the same version before using backup-utils." 1>&3
     exit 1
   fi
 fi